pyca / cryptography

cryptography is a package designed to expose cryptographic primitives and recipes to Python developers.
https://cryptography.io
Other
6.65k stars 1.53k forks source link

Poor performance in asyncssh is observed in versions of cryptography newer than 36.0.2. #9122

Closed vsafonin closed 1 year ago

vsafonin commented 1 year ago

Hello, I have noticed that my app, which uses asyncssh, has become much slower when I use a version cryptography newer than 36.0.2. This issue only occurs when I utilize an SSH key file for authentication. My app connects to 56 thousand devices simultaneously. When I use a version newer than 36.0.2, my app takes over an hour to complete and heavily burdens the processor.

To describe this problem, I have written a small test module.

import pytest
import asyncssh

from fake_ssh import Server

def handler(command):
    if command == "cat /etc/os-relase":
        return "TEST SERVER"

@pytest.fixture
def server():
    with Server(command_handler=handler) as server:
        yield server

@pytest.mark.asyncio
async def test_ssh_servier(server):
    ssh_info = {
                'host': server.host,
                'client_keys': "my_test_key",
                'port': server.port,
                'known_hosts': None,
                'keepalive_interval': 60,
                'keepalive_count_max': 90,
                'login_timeout': 90,
                'server_host_key_algs': ['ssh-dss','ssh-rsa', 'ssh-ed25519'],
                'connect_timeout': 90
                }
    for _ in range(0,50):
        connect = await asyncssh.connect(**ssh_info)
        assert connect.get_extra_info('server_version') == "SSH-2.0-paramiko_2.12.0"
        os_releas = await connect.run('cat /etc/os-relase')
        assert os_releas.stdout == "TEST SERVER"

Where 'client_keys' is the actual SSH authentication key (it should be located in the directory with the test).

This is result: if i'm using cryptography 36.0.2

(.venv) ➜  cryptography_test pip install cryptography==36.0.2
Requirement already satisfied: cryptography==36.0.2 in ./.venv/lib/python3.11/site-packages (36.0.2)
Requirement already satisfied: cffi>=1.12 in ./.venv/lib/python3.11/site-packages (from cryptography==36.0.2) (1.15.1)
Requirement already satisfied: pycparser in ./.venv/lib/python3.11/site-packages (from cffi>=1.12->cryptography==36.0.2) (2.21)
(.venv) ➜  cryptography_test time pytest test_criptography_version.py  -W ignore::DeprecationWarning
================================================================================================ test session starts ================================================================================================
platform linux -- Python 3.11.2, pytest-7.4.0, pluggy-1.2.0
rootdir: /home/vldmr/proj/test_cryptographt/tests/cryptography_test
plugins: asyncio-0.21.0
asyncio: mode=Mode.STRICT
collected 1 item

test_criptography_version.py .                                                                                                                                                                                [100%]

================================================================================================= 1 passed in 5.22s =================================================================================================
pytest test_criptography_version.py -W ignore::DeprecationWarning  3,15s user 0,24s system 62% cpu 5,400 total

if i'm using cryptography=37.0.0


(.venv) ➜  cryptography_test pip install cryptography==37.0.0
Collecting cryptography==37.0.0
  Using cached cryptography-37.0.0-cp36-abi3-manylinux_2_24_x86_64.whl (4.0 MB)
Requirement already satisfied: cffi>=1.12 in ./.venv/lib/python3.11/site-packages (from cryptography==37.0.0) (1.15.1)
Requirement already satisfied: pycparser in ./.venv/lib/python3.11/site-packages (from cffi>=1.12->cryptography==37.0.0) (2.21)
Installing collected packages: cryptography
  Attempting uninstall: cryptography
    Found existing installation: cryptography 36.0.2
    Uninstalling cryptography-36.0.2:
      Successfully uninstalled cryptography-36.0.2
Successfully installed cryptography-37.0.0
(.venv) ➜  cryptography_test time pytest test_criptography_version.py  -W ignore::DeprecationWarning
================================================================================================ test session starts ================================================================================================
platform linux -- Python 3.11.2, pytest-7.4.0, pluggy-1.2.0
rootdir: /home/vldmr/proj/test_cryptographt/tests/cryptography_test
plugins: asyncio-0.21.0
asyncio: mode=Mode.STRICT
collected 1 item

test_criptography_version.py .                                                                                                                                                                                [100%]

================================================================================================ 1 passed in 32.11s =================================================================================================
pytest test_criptography_version.py -W ignore::DeprecationWarning  30,19s user 0,30s system 94% cpu 32,332 total

if i'm using cryptography 41.0.0


(.venv) ➜  cryptography_test pip install cryptography==41.0.0
Collecting cryptography==41.0.0
  Downloading cryptography-41.0.0-cp37-abi3-manylinux_2_28_x86_64.whl (4.3 MB)
     ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 4.3/4.3 MB 3.2 MB/s eta 0:00:00
Requirement already satisfied: cffi>=1.12 in ./.venv/lib/python3.11/site-packages (from cryptography==41.0.0) (1.15.1)
Requirement already satisfied: pycparser in ./.venv/lib/python3.11/site-packages (from cffi>=1.12->cryptography==41.0.0) (2.21)
Installing collected packages: cryptography
  Attempting uninstall: cryptography
    Found existing installation: cryptography 37.0.0
    Uninstalling cryptography-37.0.0:
      Successfully uninstalled cryptography-37.0.0
Successfully installed cryptography-41.0.0
(.venv) ➜  cryptography_test time pytest test_criptography_version.py  -W ignore::DeprecationWarning
================================================================================================ test session starts ================================================================================================
platform linux -- Python 3.11.2, pytest-7.4.0, pluggy-1.2.0
rootdir: /home/vldmr/proj/test_cryptographt/tests/cryptography_test
plugins: asyncio-0.21.0
asyncio: mode=Mode.STRICT
collected 1 item

test_criptography_version.py .                                                                                                                                                                                [100%]

================================================================================================ 1 passed in 32.03s =================================================================================================
pytest test_criptography_version.py -W ignore::DeprecationWarning  30,09s user 0,32s system 94% cpu 32,233 total
(.venv) ➜  cryptography_test

Why this happen? this is possible to fix it? Thank you

alex commented 1 year ago

This likely has the same cause as https://github.com/pyca/cryptography/issues/9063, and will be fixed in our next release.

alex commented 1 year ago

Ahh, wait, alternatively, this may be caused by the fact that cryptography 37 begins to use OpenSSL 3.

I'm not aware of a specific regression that may be at work here, so some more profiling may be required.

alex commented 1 year ago

I attempted to reproduce this locally, and the tests run in about 10 seconds. However, if I run under a profiler, basically none of the time is spent in cryptography.

What key type are you using for my_test_key?

vsafonin commented 1 year ago

I attempted to reproduce this locally, and the tests run in about 10 seconds. However, if I run under a profiler, basically none of the time is spent in cryptography.

What key type are you using for my_test_key?

i'm using this: 3072 SHA256:v97YqUHeH3JIkbi3QhDlcIQzTw0IisvR9rselXDIJAg vldmr@workvm (RSA)

vsafonin commented 1 year ago

update, i checked now: this happen only with rsa key...

alex commented 1 year ago

This is very very likely to be a performance regression in OpenSSL, but let's see.

reaperhulk commented 1 year ago

I'm not sure what's going on with @alex's profiler results, but RSA key loading is substantially slower in 37+ due to changes in the way it performs key checks when calling RSA_check_key. unsafe_skip_rsa_key_validation=True as a kwarg when loading will skip this (at the cost of being potentially unsafe!) but I think you'll have to patch asyncio to test and see if that recovers/even improves performance.

alex commented 1 year ago

I also do not know what's going on with the profiler, with an RSA key I see this takes 4.5x longer, but the profiler results don't show where it's spending that time.

Nonetheless: the best choice is almost certainly to find a way to load the key a single time, right now each connection re-parses the key from disk, if you can reuse the same key object, it will be much faster. I'm not sure how to do that with asyncssh's APIs.

ronf commented 1 year ago

Yes - I think this is caused by the extra RSA checks in OpenSSL 3 mentioned above. If you want to disable those extra checks, it can be done as follows:

from cryptography.hazmat.backends.openssl import backend
backend._rsa_skip_check_key = True

This made a substantial difference in the runtime on the AsyncSSH unit tests. You can see an example of that at https://github.com/ronf/asyncssh/blob/8dba2b17f0cae4929bb5f2f4f8e888745fde1013/tests/util.py#L80-L85. I think this will be especially noticeable with larger (4K) RSA keys.

I'm not sure if there's a better way to do this that doesn't involve violating protected access.

alex commented 1 year ago

The various key loading APIs now have a public API for it: https://cryptography.io/en/latest/hazmat/primitives/asymmetric/serialization/#cryptography.hazmat.primitives.serialization.load_pem_private_key, please note the caveats though.

The best solution, if possible, would be to avoid re-loading the key on each connection.

On Fri, Jun 23, 2023 at 9:49 AM Ron Frederick @.***> wrote:

Yes - I think this is caused by the extra RSA checks in OpenSSL 3 mentioned above. If you want to disable those extra checks, it can be done as follows:

from cryptography.hazmat.backends.openssl import backendbackend._rsa_skip_check_key = True

This made a substantial difference in the runtime on the AsyncSSH unit tests. You can see an example of that at https://github.com/ronf/asyncssh/blob/8dba2b17f0cae4929bb5f2f4f8e888745fde1013/tests/util.py#L80-L85. I think this will be especially noticeable with larger (4K) RSA keys.

I'm not sure if there's a better way to do this that doesn't involve violating protected access.

— Reply to this email directly, view it on GitHub https://github.com/pyca/cryptography/issues/9122#issuecomment-1604313477, or unsubscribe https://github.com/notifications/unsubscribe-auth/AAAAGBAUEIHJYGVIYVCSOF3XMWNHPANCNFSM6AAAAAAZROPW3Q . You are receiving this because you were mentioned.Message ID: @.***>

-- All that is necessary for evil to succeed is for good people to do nothing.

vsafonin commented 1 year ago

Ok, Thank you. Now, I have enabled unsafe_skip_rsa_key_validation in the RSAPrivateKey class:

class RSAPrivateKey(_RSAKey):
    """A shim around PyCA for RSA private keys"""

    @classmethod
    def construct(cls, n: int, e: int, d: int, p: int, q: int,
                  dmp1: int, dmq1: int, iqmp: int) -> 'RSAPrivateKey':
        """Construct an RSA private key"""

        pub = rsa.RSAPublicNumbers(e, n)
        priv = rsa.RSAPrivateNumbers(p, q, d, dmp1, dmq1, iqmp, pub)
        priv_key = priv.private_key(unsafe_skip_rsa_key_validation=True)

        return cls(priv_key, pub, priv)

This code is located in the asyncssh/crypto/rsa.py file.

This solution resolves my problem for now, but I acknowledge that it is not an ideal solution. I will continue to explore alternative approaches to avoid reloading the key. However, at the moment, it seems to be impossible to achieve.

alex commented 1 year ago

I think any future follow-ups here are in asyncssh, so I'm going to close this for now. If there ends up being future action items we can take in cryptography please file a new bug!