Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

eventlet monkey_patch'ed subprocess is 10 times slower in IO than original #813

Open
dkolvakh opened this issue Oct 6, 2023 · 0 comments
Labels

Comments

@dkolvakh
Copy link

dkolvakh commented Oct 6, 2023

$ uname -a
Linux dk-VirtualBox-tmp 5.15.0-84-generic #93-Ubuntu SMP Tue Sep 5 17:16:10 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

$ python -V
Python 3.10.12

$ pip freeze
alabaster==0.7.12
apt-clone==0.2.1
apturl==0.5.2
Babel==2.8.0
beautifulsoup4==4.10.0
blinker==1.4
Brlapi==0.8.3
cachetools==5.3.0
ccsm==0.9.14.1
certifi==2020.6.20
chardet==5.1.0
click==8.0.3
colorama==0.4.6
command-not-found==0.3
compizconfig-python==0.9.14.1
configobj==5.0.6
cryptography==3.4.8
cupshelpers==1.0
dbus-python==1.2.18
defer==1.0.6
distlib==0.3.6
distro==1.7.0
dnspython==2.4.2
docutils==0.17.1
dulwich==0.21.5
eventlet==0.33.3
eyeD3==0.8.10
filelock==3.10.7
greenlet==2.0.2
grpcio==1.30.2
httplib2==0.20.2
idna==3.3
ifaddr==0.1.7
imagesize==1.3.0
IMDbPY==2021.4.18
importlib-metadata==4.6.4
jeepney==0.7.1
Jinja2==3.0.3
keyring==23.5.0
launchpadlib==1.10.16
lazr.restfulclient==0.14.4
lazr.uri==1.0.6
louis==3.20.0
Mako==1.1.3
MarkupSafe==2.0.1
more-itertools==8.10.0
netaddr==0.8.0
netifaces==0.11.0
oauthlib==3.2.0
onboard==1.4.1
openstackdocstheme==3.2.0
packaging==23.0
pbr==5.11.1
pexpect==4.8.0
Pillow==9.0.1
platformdirs==3.2.0
pluggy==1.0.0
protobuf==3.12.4
psutil==5.9.0
ptyprocess==0.7.0
py==1.10.0
pycairo==1.20.1
pycups==2.0.1
pycurl==7.44.1
pyelftools==0.27
Pygments==2.11.2
PyGObject==3.42.1
PyICU==2.8.1
PyJWT==2.3.0
PyNaCl==1.5.0
pyparsing==2.4.7
pyparted==3.11.7
pyproject_api==1.5.1
python-apt==2.4.0+ubuntu2
python-debian==0.1.43+ubuntu1.1
python-magic==0.4.24
python-xapp==2.2.2
python-xlib==0.29
pytz==2022.1
pyxdg==0.27
PyYAML==5.4.1
reportlab==3.6.8
requests==2.25.1
requests-file==1.5.1
roman==3.3
sbd==1.0.0
SecretStorage==3.3.1
setproctitle==1.2.2
six==1.16.0
snowballstemmer==2.2.0
soupsieve==2.3.1
Sphinx==4.3.2
sphinxcontrib-svg2pdfconverter==1.2.2
systemd-python==234
tldextract==3.1.2
toml==0.10.2
tomli==2.0.1
tox==4.4.8
ubuntu-drivers-common==0.0.0
ufw==0.36.1
Unidecode==1.3.3
urllib3==1.26.5
virtualenv==20.21.0
wadllib==1.3.6
xdg==5
xkit==0.0.0
youtube-dl==2021.12.17
zipp==1.0.0

Cause of the error
During monkey_patch 'eventlet' doesn't care about constants in built-in 'select' module, that's why patched 'subprocess' module falls back from linux-wide 4096 bytes to default and 'safe' 512 bytes for IO buffer trying to lookup for non-existing constant in 'eventlet.green.select' module:

python3.10/subprocess.py:

    # When select or poll has indicated that the file is writable,
    # we can write up to _PIPE_BUF bytes without risk of blocking.
    # POSIX defines PIPE_BUF as >= 512.
    _PIPE_BUF = getattr(select, 'PIPE_BUF', 512)

Steps to reproduce the error
test_write_pipes.py:

import logging
import sys
import time
logging.basicConfig(
    stream=sys.stdout, level=logging.DEBUG,
    format='[%(asctime)s] %(message)s {%(filename)s:%(lineno)d}')
LOG = logging.getLogger(__name__)

WRITE_CHUNK_SIZE = 64 * (1024 ** 2)
IMAGE_FILE_SIZE = WRITE_CHUNK_SIZE * 2


def image_file_read(chunk_size):
    data_len = 0
    while data_len < IMAGE_FILE_SIZE:
        start_time = time.time()
        data = b'*' * chunk_size
        LOG.debug(f'Generated in {(time.time() - start_time):.4f} seconds')
        yield data
        data_len += len(data)


def do_run():
    LOG.debug('START')

    for image_data in image_file_read(WRITE_CHUNK_SIZE):
        args = [
            'dd', 'of=./data_file',
        ]
        write_time = time.time()
        subprocess.run(
            args,
            input=image_data,
            capture_output=True
        )
        LOG.debug(f'Written in {(time.time() - write_time):.4f} seconds')

    LOG.debug('END')
    LOG.debug('===================================')


try:
    import subprocess
    LOG.debug('Use built-in subprocess and select libraries')
    do_run()
finally:
    pass

try:
    import eventlet
    import subprocess

    eventlet.monkey_patch()
    eventlet_patched = eventlet and eventlet.patcher.is_monkey_patched(
        subprocess)
    LOG.debug(f'{eventlet_patched=}')
    LOG.debug('Use patched by eventlet subprocess and select libraries')
    do_run()
finally:
    pass

Result:

$ python3 test_write_pipes.py
[2023-10-06 17:42:49,931] Use built-in subprocess and select libraries {test_write_pipes.py:44}
[2023-10-06 17:42:49,931] START {test_write_pipes.py:24}
[2023-10-06 17:42:49,961] Generated in 0.0298 seconds {test_write_pipes.py:18}
[2023-10-06 17:42:49,967] _PIPE_BUF=4096 {subprocess.py:2005}
[2023-10-06 17:42:51,798] Written in 1.8370 seconds {test_write_pipes.py:36}
[2023-10-06 17:42:51,828] Generated in 0.0297 seconds {test_write_pipes.py:18}
[2023-10-06 17:42:51,834] _PIPE_BUF=4096 {subprocess.py:2005}
[2023-10-06 17:42:53,259] Written in 1.4264 seconds {test_write_pipes.py:36}
[2023-10-06 17:42:53,259] END {test_write_pipes.py:38}
[2023-10-06 17:42:53,259] =================================== {test_write_pipes.py:39}
[2023-10-06 17:42:53,490] eventlet_patched=True {test_write_pipes.py:56}
[2023-10-06 17:42:53,490] Use patched by eventlet subprocess and select libraries {test_write_pipes.py:57}
[2023-10-06 17:42:53,490] START {test_write_pipes.py:24}
[2023-10-06 17:42:53,527] Generated in 0.0360 seconds {test_write_pipes.py:18}
[2023-10-06 17:42:53,531] _PIPE_BUF=512 {subprocess.py:2005}
[2023-10-06 17:43:06,731] Written in 13.2037 seconds {test_write_pipes.py:36}
[2023-10-06 17:43:06,760] Generated in 0.0288 seconds {test_write_pipes.py:18}
[2023-10-06 17:43:06,765] _PIPE_BUF=512 {subprocess.py:2005}
[2023-10-06 17:43:19,503] Written in 12.7389 seconds {test_write_pipes.py:36}
[2023-10-06 17:43:19,503] END {test_write_pipes.py:38}
[2023-10-06 17:43:19,503] =================================== {test_write_pipes.py:39}
@itamarst itamarst added the bug label Dec 19, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

2 participants