su -s /bin/sh -c "keystone-manage db_sync" keystone

Bug #2042744 reported by Aytac Tokatli
140
This bug affects 28 people
Affects Status Importance Assigned to Milestone
OpenStack Identity (keystone)
Confirmed
Critical
Unassigned
keystone (Ubuntu)
Confirmed
Undecided
Unassigned

Bug Description

When I execute su -s /bin/sh -c "keystone-manage db_sync" keystone

I am receiving below error

Exception ignored in: <function _removeHandlerRef at 0x7f01819b43a0>
Traceback (most recent call last):
  File "/usr/lib/python3.10/logging/__init__.py", line 846, in _removeHandlerRef
  File "/usr/lib/python3.10/logging/__init__.py", line 226, in _acquireLock
  File "/usr/lib/python3.10/threading.py", line 164, in acquire
  File "/usr/lib/python3/dist-packages/eventlet/green/thread.py", line 34, in get_ident
AttributeError: 'NoneType' object has no attribute 'getcurrent'

Revision history for this message
Gavo (gavo996) wrote :

Hello

I've got the same problem. I saw this log in MariaDB:

2023-11-05 3:55:39 3 [Warning] Aborted connection 3 to db: 'keystone' user: 'keystone' host: '10.88.0.2' (Got an error reading communication packets)

I played with this configuration y MariaDB, but the result was the same
max_allowed_packet=1024M

My python version:

python3.11
Alpine Linux v3.18

what have you in your environment?

Revision history for this message
Jaime Mejia (jaimemejiaues) wrote :

Hello

I got the same message on fresh SO install :

su -s /bin/sh -c "keystone-manage db_sync" keystone
Exception ignored in: <function _removeHandlerRef at 0x7f1f23f943a0>
Traceback (most recent call last):
  File "/usr/lib/python3.10/logging/__init__.py", line 846, in _removeHandlerRef
  File "/usr/lib/python3.10/logging/__init__.py", line 226, in _acquireLock
  File "/usr/lib/python3.10/threading.py", line 164, in acquire
  File "/usr/lib/python3/dist-packages/eventlet/green/thread.py", line 34, in get_ident

Enviroment:

SO: Ubuntu Server 22.04.3 LTS (Jammy Jellyfish)
OpenStack version: Bobcat

Keystone packages:

ii keystone 2:24.0.0-0ubuntu1~cloud0 all OpenStack identity service - Daemons
ii keystone-common 2:24.0.0-0ubuntu1~cloud0 all OpenStack identity service - Common files
ii python3-keystone 2:24.0.0-0ubuntu1~cloud0 all OpenStack identity service - Python 3 library
ii python3-keystoneauth1 5.3.0-0ubuntu1~cloud0 all authentication library for OpenStack Identity - Python 3.x
ii python3-keystoneclient 1:5.2.0-0ubuntu1~cloud0 all client library for the OpenStack Keystone API - Python 3.x
ii python3-keystonemiddleware 10.4.1-0ubuntu1~cloud0 all Middleware for OpenStack Identity (Keystone) - Python 3.x

Python version:

ii python3 3.10.6-1~22.04 amd64 interactive high-level object-oriented language (default python3 version)

MariaDB version:

ii libmariadb3:amd64 1:10.6.12-0ubuntu0.22.04.1 amd64 MariaDB database client library
ii mariadb-client-10.6 1:10.6.12-0ubuntu0.22.04.1 amd64 MariaDB database client binaries
ii mariadb-client-core-10.6 1:10.6.12-0ubuntu0.22.04.1 amd64 MariaDB database core client binaries
ii mariadb-common 1:10.6.12-0ubuntu0.22.04.1 all MariaDB common configuration files
ii mariadb-server 1:10.6.12-0ubuntu0.22.04.1 all MariaDB database server (metapackage depending on the latest version)
ii mariadb-server-10.6 1:10.6.12-0ubuntu0.22.04.1 amd64 MariaDB database server binaries
ii mariadb-server-core-10.6 1:10.6.12-0ubuntu0.22.04.1 amd64 MariaDB database core server files

Revision history for this message
ChosunOne (chosunone) wrote :

Also running into this bug on Ubuntu 22.04, 2023.2 Bobcat.

Revision history for this message
Dmitry Veber (night-raven1337) wrote :

Any updates? this has stopped an installation in its tracks

Revision history for this message
Jack Newbury (jacknewbury) wrote :

Anyone managed to get a fix this has stopped my install completely...

Revision history for this message
Yohann (overloaded68) wrote :

Affected too with this bug

keystone 2:22.0.0-2

Revision history for this message
Farbod Saghafi (itsfarbod) wrote :

Same problem on Ubuntu 22.04 Bobcat.

Revision history for this message
Farbod Saghafi (itsfarbod) wrote :

It seems problem solved.
What changes did you make?
I think problem was with third party packages. Maybe python logging or eventlet.
Can anybody guide me through the solution that they made to make this working?

Revision history for this message
Stéphane NOU (stephanenou) wrote :

Hello,

Same problem here on Ubuntu 22.04.3 LTS up-to-date and 2023.2 Bobcat.

- Following the official documentation :

sudo su -s /bin/sh -c "keystone-manage db_sync" keystone
Exception ignored in: <function _removeHandlerRef at 0x7f8436c383a0>
Traceback (most recent call last):
  File "/usr/lib/python3.10/logging/__init__.py", line 846, in _removeHandlerRef
  File "/usr/lib/python3.10/logging/__init__.py", line 226, in _acquireLock
  File "/usr/lib/python3.10/threading.py", line 164, in acquire
  File "/usr/lib/python3/dist-packages/eventlet/green/thread.py", line 34, in get_ident
AttributeError: 'NoneType' object has no attribute 'getcurrent'

- I see an error in /var/log/mysql/error.log

2023-11-29 16:28:39 31 [Warning] Aborted connection 31 to db: 'keystone' user: 'keystone' host: 'controller01' (Got an error reading communication packets)

- I see that tables have been added to the database:

MariaDB [keystone]> show tables;
+------------------------------------+
| Tables_in_keystone |
+------------------------------------+
| access_rule |
| access_token |
| alembic_version |
| application_credential |
| application_credential_access_rule |
| application_credential_role |
| assignment |
| config_register |
| consumer |
| credential |
| endpoint |
| endpoint_group |
| expiring_user_group_membership |
| federated_user |
| federation_protocol |
| group |
| id_mapping |
| identity_provider |
| idp_remote_ids |
| implied_role |
| limit |
| local_user |
| mapping |
| nonlocal_user |
| password |
| policy |
| policy_association |
| project |
| project_endpoint |
| project_endpoint_group |
| project_option |
| project_tag |
| region |
| registered_limit |
| request_token |
| revocation_event |
| role |
| role_option |
| sensitive_config |
| service |
| service_provider |
| system_assignment |
| token |
| trust |
| trust_role |
| user |
| user_group_membership |
| user_option |
| whitelisted_config |
+------------------------------------+

Revision history for this message
Jianer Cong (cccccje) wrote :

Yeah, I got the same problem.

After a search in the source code, I guess it's something wrong with
monkey-patching the threading python library with the eventlet package. (which
is removed in the Newtown release according to the comments in the source.)

I try the following , but to no avail:

sudo -u keystone keystone-manage --standard-threads db_sync

The --standard-threads option is supposed to disable the monkey-patching, but it
doesn't seem to work....

I guess it's something wrong with the code in the sql.py ? I can still see
eventlet server being used in that file....😭

Antoine Thys (thystips)
Changed in keystone:
status: New → Confirmed
Revision history for this message
Yosep Kim (800whr) wrote :

I am having the same issue. Is there any version that I should try to install instead for the time being? Thank you.

Revision history for this message
Antoine Thys (thystips) wrote :

This issue is weird, I have the same error but it seems that it has no influence on keystone deployment.

I have this error on db_sync but after that Keystone seems working normally.

Revision history for this message
Yosep Kim (800whr) wrote :

I am getting the same error when trying to set up fernet, which is the very next step after the database population step:

# keystone-manage fernet_setup --keystone-user keystone --keystone-group keystone
Exception ignored in: <function _removeHandlerRef at 0x7f7d7d4743a0>
Traceback (most recent call last):
  File "/usr/lib/python3.10/logging/__init__.py", line 846, in _removeHandlerRef
  File "/usr/lib/python3.10/logging/__init__.py", line 226, in _acquireLock
  File "/usr/lib/python3.10/threading.py", line 164, in acquire
  File "/usr/lib/python3/dist-packages/eventlet/green/thread.py", line 34, in get_ident
AttributeError: 'NoneType' object has no attribute 'getcurrent'

Revision history for this message
dim_s (kostyukdv) wrote :

Hi, same bug on fresh install of bobcat.
Should I go to downgrade to antelope release to fix this?

description: updated
Revision history for this message
Francisco (fralem1) wrote :

Same issue here on fresh install on debian 12 (bookworm), Python 3.11.2.

Revision history for this message
dim_s (kostyukdv) wrote :

Tried Antelope version on ubuntu 22.04, there is no problems :(

Revision history for this message
Diego (dmarron) wrote :

Same issue on Debian 13/sid
Confirmed issue with python 3.11 and 3.10

This issue is a *major blocker* to deploy openstack in more up-to-date platforms
I would argue for some urgency, since its almost 2 months this issue was open.

$ keystone-manage db_sync
Exception ignored in: <function _removeHandlerRef at 0x3fd4ad5940>
Traceback (most recent call last):
  File "/usr/lib/python3.11/logging/__init__.py", line 855, in _removeHandlerRef
  File "/usr/lib/python3.11/logging/__init__.py", line 235, in _acquireLock
  File "/usr/lib/python3.11/threading.py", line 164, in acquire
  File "/usr/lib/python3/dist-packages/eventlet/green/thread.py", line 34, in get_ident
AttributeError: 'NoneType' object has no attribute 'getcurrent'

Revision history for this message
Diego (dmarron) wrote (last edit ):

I've been digging around.

It seems that at some poing after running `keystone-manage db_sync` some (all?) runtime objects are gone (NoneType)

To illustrate the issue, I modified the get_ident function in eventlet/green/thread.py to:
(the function triggering the initial bug report)

---------------------------------

from eventlet import sleep

def get_ident(gr=None):
    if gr is None:
        print("get_ident: gr is NONE. greenlet:", greenlet)
        try:
            sleep(0.01)
            current = greenlet.getcurrent()
        except:
            sleep(5)
            current = greenlet.getcurrent()

        print(" greenlet.getcurrent returned:",current)
        return current
        #return id(greenlet.getcurrent())
    else:
        print("get_ident: gr is {}".format(gr))
        return id(gr)

---------------------------------
The output:

lots of the following:

get_ident: gr is NONE. greenlet: <module 'eventlet.support.greenlets' from '/home/sipeed/venv/del_keystone/lib/python3.10/site-packages/eventlet/support/greenlets.py'>
           greenlet.getcurrent returned: <greenlet.greenlet object at 0x3fdddae8c0 (otid=0x3fdddb4510) current active started main>

Then, the last one is:

get_ident: gr is NONE. greenlet: None
Exception ignored in: <function _removeHandlerRef at 0x3fdebe1480>

Traceback (most recent call last):
  File "/usr/lib/python3.10/logging/__init__.py", line 846, in _removeHandlerRef
  File "/usr/lib/python3.10/logging/__init__.py", line 226, in _acquireLock
  File "/usr/lib/python3.10/threading.py", line 164, in acquire
  File "/home/sipeed/venv/del_keystone/lib/python3.10/site-packages/eventlet/green/thread.py", line 38, in get_ident
TypeError: 'NoneType' object is not callable

Now the exception happens when trying to call sleep(5), the same function it was able to call many times in sleep(0.01)

Revision history for this message
Brian Garzon (alexg94) wrote :

Hi, same issue here Ubuntu 22. maybe any update about it?

I've tried with openstack bobcat and now with antelope but error comes up again. I had to use zed.

Revision history for this message
Oskar Berggren (oskar-berggren) wrote :

Same problem here. Ubuntu 22. Very frustrating

Revision history for this message
Launchpad Janitor (janitor) wrote :

Status changed to 'Confirmed' because the bug affects multiple users.

Changed in keystone (Ubuntu):
status: New → Confirmed
Revision history for this message
Josh (h-josh-u) wrote :

Confirming I'm seeing the same problem on Rocky 9

Revision history for this message
Greg Oster (gregoster) wrote :

Environment: Debian 12.4, Python 3.11.2. Pristine install.

After a few hours digging: the call to main() in /usr/bin/keystone-manage has already completed before the exception occurs, and thus this error is actually happening during python
shutdown. In /usr/lib/python3/dist-packages/oslo_log/log.py in the function setup() you can simply remove the call to _fix_eventlet_logging(), and the exception goes away. Digging further, it seems that the lines:

        logging.threading = eventlet.green.threading
        logging._lock = logging.threading.RLock()

in _fix_eventlet_logging() together are the trigger - commenting out either of them is sufficient to get rid of the exception.

I'm already much farther down this rabbit hole than I intended, but perhaps the answer as to what is going on here will be obvious to someone with more knowledge about python, its threading models, and logging...

Revision history for this message
Oskar Berggren (oskar-berggren) wrote :

@gregoster, thanks a lot, that was interesting!

If the error happens during python shutdown, it sounds like it should have already done its work by then, but no database tables appeared for me. And commenting out one of those code lines made the error disappear, yet still not tables appeared in the database.

Turns out the issue was that the guide I followed didn't mention that keystone-manage will not actually tell you what's wrong on the console. By random chance I got the idea to check if there was any log file and yes there is and in there it was actually complaining that I had not installed some python Postgresql package (psycopg2).

As for the thread related exception... I wonder if this recent commit to remove some lingering eventlet references from keystone might fix it:
https://opendev.org/openstack/keystone/commit/406233f16975a83ca41b0d057d1497b6d43ee0fa

Revision history for this message
Greg Oster (gregoster) wrote :
Download full text (4.1 KiB)

@oskar-bergren Same issue with the recent commit. I grabbed the latest from https://opendev.org/openstack/keystone and ran that, and it still failed :(

(base) me@node2:~/keystone$ keystone-manage db_sync 10:05:14 [144/1749]
Config file not found, using default configs.
2024-02-09 16:05:14.209 26507 INFO alembic.runtime.migration [-] Context impl SQLiteImpl.
2024-02-09 16:05:14.210 26507 INFO alembic.runtime.migration [-] Will assume non-transactional DDL.
2024-02-09 16:05:14.215 26507 INFO alembic.runtime.migration [-] Running upgrade -> 27e647c0fad4, Initial version.
2024-02-09 16:05:14.240 26507 INFO alembic.runtime.migration [-] Running upgrade 27e647c0fad4 -> 29e87d24a316, Initial no-op Yoga expand migration.
2024-02-09 16:05:14.240 26507 INFO alembic.runtime.migration [-] Running upgrade 29e87d24a316 -> b4f8b3f584e0, Fix incorrect constraints.
2024-02-09 16:05:14.244 26507 INFO alembic.runtime.migration [-] Running upgrade b4f8b3f584e0 -> 11c3b243b4cb, Remove service_provider.relay_state_prefix server default.
2024-02-09 16:05:14.247 26507 INFO alembic.runtime.migration [-] Running upgrade 11c3b243b4cb -> 47147121, Add Identity Federation attribute mapping schema version.
2024-02-09 16:05:14.247 26507 INFO alembic.runtime.migration [-] Running upgrade 27e647c0fad4 -> e25ffa003242, Initial no-op Yoga contract migration.
2024-02-09 16:05:14.248 26507 INFO alembic.runtime.migration [-] Running upgrade e25ffa003242 -> 99de3849d860, Fix incorrect constraints.
2024-02-09 16:05:14.254 26507 INFO alembic.runtime.migration [-] Running upgrade 99de3849d860 -> c88cdce8f248, Remove duplicate constraints.
Exception ignored in: <function _removeHandlerRef at 0x7f5bfc17db20>
Traceback (most recent call last):
  File "/home/me/anaconda3/lib/python3.11/logging/__init__.py", line 855, in _removeHandlerRef ...

Read more...

Revision history for this message
Greg Oster (gregoster) wrote :

More details...... I wanted to make a minimal replicator for this issue. I started with the command 'keystone-manage db_version', as this seemed to be the 'simplest' example I could find that would replicate the exception. I then started hacking out code, with the idea that if I took out code, and the exception still occured, I didn't need the removed code for the replicator. Where I got to was:

In keystone/cmd/mangage.py I could remove everything except:
from keystone.cmd import cli
and from keystone/cmd/cli.py the only line needed to replicate the issue is:
from keystone.server import backends
and if we look in keystone/server/backends.py it's the line:
from keystone import application_credential
where in keystone/application_credential/__init__.py it's just this line:
from keystone.application_credential.core import *
and then keystone/application_credential/core.py it's this line that is the one that causes the issue:
from keystone import notifications
HOWEVER: in keystone/notifications.py , it's exactly these two lines:
import flask
import oslo_messaging
that are necessary for the exception. Remove either of those two, and things work fine.

In the attached replicator code 'replicator.py', you can find my replacement for keystone/notifications.py as 'replicator_lib.py'. You'll note that replicator_lib.py needs to contain the two lines:

import flask
import oslo_messaging

I note, however, that if you bring the importing of flask and oslo_messaging into replicator.py, things work again. The lines *must* be in something that is imported in order to trigger the exception.

To run the replicator:
virtualenv foo
source foo/bin/activate
pip install flask oslo_messaging
python3 replicator.py

Note that nothing of keystone is actually used here.

And now, if you want the exception to go away, the following change will work. Add the line:

import flask

into keystone/application_credential/core.py after the line:

from keystone import notifications

And then 'keystone-manage db_sync' et al. will work without tossing an
exception. Why? I have absolutely no clue.

Revision history for this message
Greg Oster (gregoster) wrote :

For what it's worth, not seeing the exception on Ubuntu 22.04.4 LTS today.

Revision history for this message
Stefan Staffler (04setupwizard17) wrote (last edit ):

I have installed a fresh Ubuntu 22.04.3 LTS with latest updates (apt dist-upgrade) today and the exception of the db_sync command did not come up. With an Ubuntu 22.04.3 LTS installation about one or two month ago, the installation has thrown the exception as well.

Does it might be a dependency issue of the older versions?

Revision history for this message
Shebin Thomas (tshebin) wrote (last edit ):

hey could anyone guide me with the steps required as i still am getting the same error i am using ubuntu 22.04.3 server version

su -s /bin/bash -c "keystone-manage db_sync" keystone
Traceback (most recent call last):
  File "/usr/bin/keystone-manage", line 10, in <module>
    sys.exit(main())
  File "/usr/lib/python3/dist-packages/keystone/cmd/manage.py", line 41, in main
    cli.main(argv=sys.argv, developer_config_file=developer_config)
  File "/usr/lib/python3/dist-packages/keystone/cmd/cli.py", line 1359, in main
    keystone.conf.setup_logging()
  File "/usr/lib/python3/dist-packages/keystone/conf/__init__.py", line 129, in setup_logging
    log.setup(CONF, 'keystone')
  File "/usr/lib/python3/dist-packages/oslo_log/log.py", line 291, in setup
    _setup_logging_from_conf(conf, product_name, version)
  File "/usr/lib/python3/dist-packages/oslo_log/log.py", line 399, in _setup_logging_from_conf
    filelog = file_handler(logpath)
  File "/usr/lib/python3.10/logging/handlers.py", line 479, in __init__
    logging.FileHandler.__init__(self, filename, mode=mode,
  File "/usr/lib/python3.10/logging/__init__.py", line 1169, in __init__
    StreamHandler.__init__(self, self._open())
  File "/usr/lib/python3.10/logging/__init__.py", line 1201, in _open
    return open_func(self.baseFilename, self.mode,
PermissionError: [Errno 13] Permission denied: '/var/log/keystone/keystone-manage.log'
Exception ignored in: <function _removeHandlerRef at 0x7f25b73183a0>
Traceback (most recent call last):
  File "/usr/lib/python3.10/logging/__init__.py", line 846, in _removeHandlerRef
  File "/usr/lib/python3.10/logging/__init__.py", line 226, in _acquireLock
  File "/usr/lib/python3.10/threading.py", line 164, in acquire
  File "/usr/lib/python3/dist-packages/eventlet/green/thread.py", line 33, in get_ident
AttributeError: 'NoneType' object has no attribute 'getcurrent'

Revision history for this message
git.user (git.user) wrote :

looks like kind of use-after-free
I tried to trace it
/usr/lib/python3/dist-packages/eventlet/green/thread.py
...
def get_ident(gr=None):
  traceback.print_stack()
...
and got AttributeError: 'NoneType' object has no attribute 'print_stack'

On the other side if traceback one level up
/usr/lib/python3.10/threading.py
 def acquire(self, blocking=True, timeout=-1):
...
traceback.print_stack()

then last 2 stacks begins with sys.exit() and h.close():

File "/usr/bin/keystone-manage", line 10, in <module>
  sys.exit(main())
....
File "/usr/lib/python3.10/threading.py", line 165, in acquire
  traceback.print_stack()
File "/usr/lib/python3.10/logging/__init__.py", line 2183, in shutdown
  h.close()
...
File "/usr/lib/python3.10/threading.py", line 165, in acquire
  traceback.print_stack()

David Wilde (dave-wilde)
Changed in keystone:
importance: Undecided → Critical
Revision history for this message
git.user (git.user) wrote :

Seems like it's a weakref black magic. wr is dead when _removeHandlerRef called
It's too much for me, I just hack it out:
def _removeHandlerRef(wr):
    """
...
    if wr() is None:
        return
...

Revision history for this message
Shebin Thomas (tshebin) wrote :

guys the error occurs because of the permissions of keystone user
grep keystone /etc/passwd if this commands gives the result with something like this /usr/sbin/nologin or /bin/false then change it using usermod -s /bin/bash keystone after this install and configure within the keystone user or in root user also make sure the keystone user is not flagged as system account.
This helped me in setting the keystone i am using ubuntu 22.04.03 lts and openstack antelope

Revision history for this message
Florin Andrei (florin-andrei) wrote :

This has nothing to do with the shell. I've changed the shell to /bin/bash, then `su - keystone` then `keystone-manage db_sync` and I still get the error.

I'm stuck trying to install it on Ubuntu 22.04.4 LTS.

Revision history for this message
Patrick McClory (pmdev) wrote :

W/ a fresh install of 22.04.04 + bobcat, not seeing the suggested fix from @tshebin work:

```
root@utility-04:/home/pmdev# grep keystone /etc/passwd
keystone:x:122:130::/var/lib/keystone:/bin/bash
root@utility-04:/home/pmdev# su -s /bin/sh -c "keystone-manage db_sync" keystone
Exception ignored in: <function _removeHandlerRef at 0x7f2ffd0b04c0>
Traceback (most recent call last):
  File "/usr/lib/python3.10/logging/__init__.py", line 846, in _removeHandlerRef
  File "/usr/lib/python3.10/logging/__init__.py", line 226, in _acquireLock
  File "/usr/lib/python3.10/threading.py", line 164, in acquire
  File "/usr/lib/python3/dist-packages/eventlet/green/thread.py", line 34, in get_ident
AttributeError: 'NoneType' object has no attribute 'getcurrent'
```

Revision history for this message
Alexandr (f11gar0) wrote :

i FIX this with some thread.py edit:

vi /usr/lib/python3/dist-packages/eventlet/green/thread.py
(or your path to thread.py from exception traceback)
find this code:

def get_ident(gr=None):
    if gr is None:
        return id(greenlet.getcurrent())
    else:
        return id(gr)

and make try-except contruction for get id like this:

def get_ident(gr=None):
    try:
        if gr is None:
            return id(greenlet.getcurrent())
        else:
            return id(gr)
    except:
        return id(gr)

retry:
su -s /bin/bash keystone -c "keystone-manage db_sync"

Revision history for this message
Vinicius Stocker (vinicius-sto) wrote :

The fix provided by @f11gar0 solved the problem for me. Thank you dear friend!

willzhang (willubt)
information type: Public → Public Security
Revision history for this message
Jeremy Stanley (fungi) wrote :

When switching a bug's type from Public to Public Security, please clarify what about it leads you to suspect it represents an exploitable vulnerability. I'm switching it back to a regular Public bug in the meantime.

If this was triggered by the earlier mention of a use-after-free condition, it didn't seem to imply that the underlying bug was inside keystone, but maybe should be filed against the eventlet project instead.

information type: Public Security → Public
Revision history for this message
David Wilde (dave-wilde) wrote :

@f11gar0, thank you for the research on this. Since you've modified eventlet code it's not possible for Keystone to carry it directly but I'm wondering if you've submitted this code to the eventlet repository and/or if there is a public bug about this issue that has bee filed there?

Thanks again!

To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.