[4.1.1] CentOS 7 + Python 3.6.8 + Ceph 15.2.16: `RecursionError: maximum recursion depth exceeded in comparison`

hswong3i commented 2 years ago

My environment:

[root@cp-nightsky ~]# cat /etc/os-release 
NAME="CentOS Linux"
VERSION="7 (Core)"
ID="centos"
ID_LIKE="rhel fedora"
VERSION_ID="7"
PRETTY_NAME="CentOS Linux 7 (Core)"
ANSI_COLOR="0;31"
CPE_NAME="cpe:/o:centos:centos:7"
HOME_URL="https://www.centos.org/"
BUG_REPORT_URL="https://bugs.centos.org/"

CENTOS_MANTISBT_PROJECT="CentOS-7"
CENTOS_MANTISBT_PROJECT_VERSION="7"
REDHAT_SUPPORT_PRODUCT="centos"
REDHAT_SUPPORT_PRODUCT_VERSION="7"

[root@cp-nightsky ~]# python3 --version
Python 3.6.8

[root@cp-nightsky ~]# ceph --version
ceph version 15.2.16 (d46a73d6d0a67a79558054a3a5a72cb561724974) octopus (stable)

If running with typing-extensions == 4.1.1 which should be the last compatible version with Python 3.6, it failed with following error message (trigger by https://github.com/ceph/ceph/blob/v15.2.16/src/pybind/mgr/pg_autoscaler/module.py#L325 and finally failed with https://github.com/python/typing/blob/4.1.1/typing_extensions/src/typing_extensions.py#L426):

[root@cp-nightsky ~]# pip list | grep typing-extensions
typing-extensions      4.1.1

[root@cp-nightsky ~]# systemctl restart ceph-mgr@cp-nightsky.service

[root@cp-nightsky ~]# journalctl -xef -u ceph-mgr@cp-nightsky.service
May 12 06:16:39 cp-nightsky.novalocal systemd[1]: Started Ceph cluster manager daemon.
-- Subject: Unit ceph-mgr@cp-nightsky.service has finished start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit ceph-mgr@cp-nightsky.service has finished starting up.
-- 
-- The start-up result is done.
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: 2022-05-12T06:16:51.181+0000 7fe3eb521700 -1 log_channel(cluster) log [ERR] : Unhandled exception from module 'pg_autoscaler' while running on mgr.cp-nightsky: maximum recursion depth exceeded in comparison
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: 2022-05-12T06:16:51.182+0000 7fe3eb521700 -1 pg_autoscaler.serve:
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: 2022-05-12T06:16:51.182+0000 7fe3eb521700 -1 Traceback (most recent call last):
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: File "/usr/share/ceph/mgr/pg_autoscaler/module.py", line 206, in serve
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: self._maybe_adjust()
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: File "/usr/share/ceph/mgr/pg_autoscaler/module.py", line 423, in _maybe_adjust
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: ps, root_map, pool_root = self._get_pool_status(osdmap, pools)
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: File "/usr/share/ceph/mgr/pg_autoscaler/module.py", line 325, in _get_pool_status
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: self.log.debug('skipping empty subtree %s', cr_name)
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: File "/lib64/python3.6/logging/__init__.py", line 1296, in debug
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: self._log(DEBUG, msg, args, **kwargs)
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: File "/lib64/python3.6/logging/__init__.py", line 1443, in _log
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: exc_info, func, extra, sinfo)
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: File "/lib64/python3.6/logging/__init__.py", line 1413, in makeRecord
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: sinfo)
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: File "/lib64/python3.6/logging/__init__.py", line 277, in __init__
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: if (args and len(args) == 1 and isinstance(args[0], collections.Mapping)
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: File "/lib64/python3.6/abc.py", line 193, in __instancecheck__
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: return cls.__subclasscheck__(subclass)
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: File "/lib64/python3.6/abc.py", line 228, in __subclasscheck__
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: if issubclass(subclass, scls):
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: File "/lib64/python3.6/abc.py", line 228, in __subclasscheck__
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: if issubclass(subclass, scls):
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: File "/lib64/python3.6/typing.py", line 1154, in __subclasscheck__
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: return super().__subclasscheck__(cls)
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: File "/lib64/python3.6/abc.py", line 228, in __subclasscheck__
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: if issubclass(subclass, scls):
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: File "/lib/python3.6/site-packages/typing_extensions.py", line 426, in __subclasscheck__
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: if issubclass(subclass, scls):
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: File "/lib/python3.6/site-packages/typing_extensions.py", line 426, in __subclasscheck__
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: if issubclass(subclass, scls):
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: File "/lib/python3.6/site-packages/typing_extensions.py", line 426, in __subclasscheck__
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: if issubclass(subclass, scls):
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: [Previous line repeated 239 more times]
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: File "/lib/python3.6/site-packages/typing_extensions.py", line 421, in __subclasscheck__
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: if self.__extra__ in subclass.__mro__:
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: RecursionError: maximum recursion depth exceeded in comparison
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: 2022-05-12T06:16:51.291+0000 7fe3de3c7700 -1 client.0 error registering admin socket command: (17) File exists
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: 2022-05-12T06:16:51.291+0000 7fe3de3c7700 -1 client.0 error registering admin socket command: (17) File exists
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: 2022-05-12T06:16:51.291+0000 7fe3de3c7700 -1 client.0 error registering admin socket command: (17) File exists
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: 2022-05-12T06:16:51.291+0000 7fe3de3c7700 -1 client.0 error registering admin socket command: (17) File exists
May 12 06:16:51 cp-nightsky.novalocal ceph-mgr[1719]: 2022-05-12T06:16:51.291+0000 7fe3de3c7700 -1 client.0 error registering admin socket command: (17) File exists

If rolling back to typing-extensions == 3.7.4.3 the error message gone and all working well:

[root@cp-nightsky ~]# pip list | grep typing-extensions
typing-extensions      3.7.4.3

[root@cp-nightsky ~]# systemctl restart ceph-mgr@cp-nightsky.service

[root@cp-nightsky ~]# journalctl -xef -u ceph-mgr@cp-nightsky.service
May 12 06:25:38 cp-nightsky.novalocal systemd[1]: Started Ceph cluster manager daemon.
-- Subject: Unit ceph-mgr@cp-nightsky.service has finished start-up
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- Unit ceph-mgr@cp-nightsky.service has finished starting up.
-- 
-- The start-up result is done.

Since downgrade typing-extension did the trick, it looks like something wrong with the 4.1.1 + Python 3.6 (which should be supported)? But I give a manually diff between 3.7.4.3..4.1.1 for bug related range seems nothing special for failling:

 class _ExtensionsGenericMeta(GenericMeta):
     def __subclasscheck__(self, subclass):
         """This mimics a more modern GenericMeta.__subclasscheck__() logic
         (that does not have problems with recursion) to work around interactions
         between collections, typing, and typing_extensions on older
         versions of Python, see https://github.com/python/typing/issues/501.
         """
-        if sys.version_info[:3] >= (3, 5, 3) or sys.version_info[:3] < (3, 5, 0):
-            if self.__origin__ is not None:
-                if sys._getframe(1).f_globals['__name__'] not in ['abc', 'functools']:
-                    raise TypeError("Parameterized generics cannot be used with class "
-                                    "or instance checks")
-                return False
+        if self.__origin__ is not None:
+            if sys._getframe(1).f_globals['__name__'] not in ['abc', 'functools']:
+                raise TypeError("Parameterized generics cannot be used with class "
+                                "or instance checks")
+            return False
         if not self.__extra__:
             return super().__subclasscheck__(subclass)
         res = self.__extra__.__subclasshook__(subclass)
         if res is not NotImplemented:
             return res
         if self.__extra__ in subclass.__mro__:
             return True
         for scls in self.__extra__.__subclasses__():
             if isinstance(scls, GenericMeta):
                 continue
             if issubclass(subclass, scls):
                 return True
         return False

srittau commented 2 years ago

Thank you for the report. I don't have time for a detailed analysis just now, but just a few data points:

The code causing this is not present in HEAD anymore.
The comment at the start of the quoted block explicitly points out that "more modern GenericMeta.__subclasscheck__() logic [...] does not have problems with recursion", so such a recursion problem seems a bit expected.
The comment links python/typing#501, which was fixed in python/typing#503 (which is the PR that introduced the problematic code).

hswong3i commented 2 years ago

But the main question is: both version coming with such ‘class _ExtensionsGenericMeta(GenericMeta):’ with minor differences due to the remove support for Python 3.5, but the NEWER 4.1.1 failed unexpectedly :-S

From the backtrack log point of view, I couldn’t find any else related code block, too… Maybe due to my limited understanding about how typing-extensions works…

JelleZijlstra commented 2 years ago

Is this reproducible on newer versions of Python and typing-extensions? We don't support 3.6 any more, and we won't be creating a patch release for the 4.1.x series.

A simple workaround should be to write self.log.debug('skipping empty subtree %s', str(cr_name)).

hswong3i commented 2 years ago

Is this reproducible on newer versions of Python and typing-extensions? We don't support 3.6 any more, and we won't be creating a patch release for the 4.1.x series.

A simple workaround should be to write self.log.debug('skipping empty subtree %s', str(cr_name)).

My key concern is even I could manually patch my packaging release as below, and manually skip Python 3.6 for 4.1.1 as my own wish:

But when using pip list --out-dated it will still showing 4.1.1 as available upgrade for me which is confusing...

I had checked all typing-extensions >3.7.4.3, <4.2.0 will break above Ceph 15.2.16, so from my point of view we shouldn't claim these affected version as Python 3.6 ready...

Anyway, ideally it would be much better for a minor patch release, e.g. 4.1.2, which fix this Python 3.6 conflict issue?

JelleZijlstra commented 2 years ago

Python 3.6 is no longer supported and we won't provide patch releases for 4.1.x. You're welcome to patch the package yourself in your packaging system.

Also, the bad code has apparently been out for nearly five years, so I doubt it's a common problem for users of 3.6.

rkachach commented 5 months ago

@hswong3i thanks for reporting the issue and for the workaround because we ran in the same BUG :pray:

python / typing_extensions

[4.1.1] CentOS 7 + Python 3.6.8 + Ceph 15.2.16: `RecursionError: maximum recursion depth exceeded in comparison` #10