python -c "import requests" got a lot slower

[gtrainavicius]

We have noticed that 'import requests' statement started taking roughly 3 times more time between versions 2.12.0 (bad) and 2.11.1 (last known good), the difference is especially visible running on Raspberry Pi 3.

Expected Result

'import requests' execution time should not increase by 3-4 times between versions.

Actual Result

3-4 times slower 'import requests' execution.

Reproduction Steps

pi@raspberrypi:~ $ sudo pip install 'requests<2.12.1'
Collecting requests<2.12.1
  Downloading requests-2.12.0-py2.py3-none-any.whl (574kB)
    100% |████████████████████████████████| 583kB 363kB/s
Installing collected packages: requests
  Found existing installation: requests 2.12.1
    Uninstalling requests-2.12.1:
      Successfully uninstalled requests-2.12.1
Successfully installed requests-2.12.0
pi@raspberrypi:~ $ time python -c "import requests"

real    0m1.761s
user    0m1.640s
sys     0m0.080s
pi@raspberrypi:~ $ sudo pip install 'requests<2.12.0'
Collecting requests<2.12.0
  Using cached requests-2.11.1-py2.py3-none-any.whl
Installing collected packages: requests
  Found existing installation: requests 2.12.0
    Uninstalling requests-2.12.0:
      Successfully uninstalled requests-2.12.0
Successfully installed requests-2.11.1
pi@raspberrypi:~ $ time python -c "import requests"

real    0m0.420s
user    0m0.370s
sys     0m0.040s

System Information

pi@raspberrypi:~ $ python --version
Python 2.7.13
pi@raspberrypi:~ $ uname -a
Linux raspberrypi 4.9.41-v7+ #1023 SMP Tue Aug 8 16:00:15 BST 2017 armv7l GNU/Linux

Raspbian Stretch.

[gtrainavicius]

I found this similar issue: #3213 maybe it's relevant.

[sigmavirus24]

What other packages do you have installed? Specifically, it's likely that you have ancient versions of pyOpenSSL and Cryptography installed which are causing this.

[gtrainavicius]

After upgarding pyOpenSSL from 16.2 to 17.2 (which implicitly upgraded cryptography to 2.0.3, not sure from which previous version) and using latest requests version (2.18.4) the time improved to:

real    0m0.854s
user    0m0.760s
sys     0m0.070s

That is still, however, considerably larger than what requests-2.11.1 used to be. Do you have any other ideas?

[gtrainavicius]

Now the python -m requests.help worked on the latest version, here is the output:

{
  "chardet": {
    "version": "3.0.4"
  },
  "cryptography": {
    "version": "2.0.3"
  },
  "idna": {
    "version": "2.6"
  },
  "implementation": {
    "name": "CPython",
    "version": "2.7.13"
  },
  "platform": {
    "release": "4.9.41-v7+",
    "system": "Linux"
  },
  "pyOpenSSL": {
    "openssl_version": "1010006f",
    "version": "17.2.0"
  },
  "requests": {
    "version": "2.18.4"
  },
  "system_ssl": {
    "version": "1010006f"
  },
  "urllib3": {
    "version": "1.22"
  },
  "using_pyopenssl": true
}

[sigmavirus24]

There are a lot of changes between 2.11.x and the latest version. For example, we now depend on idna as well which if I remember correctly used to also be rather slow to import. I wonder what kind of performance you see if you use a virtualenv without pyOpenSSL installed with 2.18.x

[kennethreitz]

We should warn on old pyOpenSSLs for slowness.

[ghost]

I'd like to add warnings for older versions pyOpenSSL. Should I open a new issue?

[kennethreitz]

yes

[gtrainavicius]

Still, warning won't solve twice as long time for importing than it used to be in older versions... Is there something more that could be done?

[kennethreitz]

Related: #4315

[methane]

One big change between 2.11 and 2.12 is chardet dependency.

[methane]

But chardet takes only 10~20% of import time on amd64 machine.

@gtrainavicius Could you try time python -c 'import chardet'?

And could you try python -v -c 'import requests' 2> request-import.txt and post it to gist?

[gtrainavicius]

pi@raspberrypi:~ $ time python -c 'import chardet'

real    0m0.098s
user    0m0.080s
sys     0m0.020s
pi@raspberrypi:~ $ time python -c 'import chardet'

real    0m0.052s
user    0m0.050s
sys     0m0.000s
pi@raspberrypi:~ $ time python -c 'import chardet'

real    0m0.099s
user    0m0.090s
sys     0m0.000s

pi@raspberrypi:~ $ time python -c 'import requests'

real    0m0.821s
user    0m0.730s
sys     0m0.070s
pi@raspberrypi:~ $ time python -c 'import requests'

real    0m0.844s
user    0m0.720s
sys     0m0.110s
pi@raspberrypi:~ $ python -v -c 'import requests' 2> requests-import.txt

The output is available here: https://pastebin.com/qAvhRbVK

[sigmavirus24]

L325 imports OpenSSL which is the module for pyOpenSSL. This leads to an import of cryptography which also imports asn1crypto

Can you try the following:

time python -c 'import cryptography.x509'
time python -c 'import cryptography.hazmat.primitives.asymmetric'
time python -c 'import asn1crypto'
time python -c 'import asn1crypto.parser'

If you're still using the versions of our dependencies that you mentioned, I'm frankly surprised you're seeing this behaviour.

[gtrainavicius]

Hey, the versions did change, pasting the updated information below. Also the above requests-import.txt was produced running requests-2.12.4. Just in case I will create another one using the latest version (requests-2.18.4): https://pastebin.com/3fdTuyR1 - it also contains 'import' time info at the top.

{
  "chardet": {
    "version": "3.0.4"
  },
  "cryptography": {
    "version": "2.1.3"
  },
  "idna": {
    "version": "2.6"
  },
  "implementation": {
    "name": "CPython",
    "version": "2.7.13"
  },
  "platform": {
    "release": "4.9.61-v7+",
    "system": "Linux"
  },
  "pyOpenSSL": {
    "openssl_version": "1010006f",
    "version": "17.3.0"
  },
  "requests": {
    "version": "2.18.4"
  },
  "system_ssl": {
    "version": "1010006f"
  },
  "urllib3": {
    "version": "1.22"
  },
  "using_pyopenssl": true
}

Here are the cryptography import timings:

pi@raspberrypi:~ $ time python -c 'import cryptography.x509'

real    0m0.528s
user    0m0.500s
sys     0m0.020s
pi@raspberrypi:~ $ time python -c 'import cryptography.hazmat.primitives.asymmetric'

real    0m0.123s
user    0m0.080s
sys     0m0.030s
pi@raspberrypi:~ $ time python -c 'import asn1crypto'

real    0m0.099s
user    0m0.080s
sys     0m0.010s
pi@raspberrypi:~ $ time python -c 'import asn1crypto.parser'

real    0m0.244s
user    0m0.220s
sys     0m0.020s

[sigmavirus24]

Yep, so as I expected, there's a total of .995s just in Cryptography (and its imports). With chardet at .05 that puts us over 1s easily.

It's possible that the chardet import may get slower. We're investigating relying on CFFI or Cython to improve its performance.

@gtrainavicius I wonder, you're using Python 2.7.13 and you have pyOpenSSL installed, is there a reason for that?

[gtrainavicius]

No reason, pyOpenSSL was installed by default on Raspbian, though not the latest version.

What we really want is to have requests library as fast as in the older versions, in our scripts that depend on it we're not using almost any other libraries...

[sigmavirus24]

@gtrainavicius the problem, however, is that Requests expects users to manage their environment appropriately. This means that we expect users to know if we need pyOpenSSL for security and have it installed (or not) in their environment. What's taking up almost all of th etime you're experiencing is pyOpenSSL and its dependencies. I think there's nothing more we can do to help with this.

[gtrainavicius]

Ah, it didn't occur to me that pyOpenSSL was optional. With it uninstalled, the time to import requests seems close enough to what it used to be:

pi@raspberrypi:~ $ time python -c 'import requests'

real 0m0.488s
user 0m0.420s
sys 0m0.050s