René's URL Explorer Experiment

{"@context":"https://schema.org","@type":"DiscussionForumPosting","headline":"Inefficient ssl.SSLWantReadError exception slows down very common use-case","articleBody":"# Bug report\r\n\r\n### Bug description:\r\n\r\nEvent loops like uvloop, asyncio use nonblocking ssl. They typically \r\n\r\n1. read data from the socket when epoll returns that it is ready\r\n2. push data to the incoming MemoryBIO\r\n3. read from SSLObject until SSLWantReadError is thrown\r\n4. pass read data to the application protocol\r\n\r\nwhen peers are exchanging relatively small messages, SSLObject.read is typically called 2 times . First call returns data, second - throws SSLWantReadError\r\n\r\nperf shows that the second call is almost as expensive as the first call because of time spent on constructing new exception object. \r\n\r\nIs it possible to optimize exception object creation for the second call?\r\n\r\nI tried to avoid the second call by analyzing MemoryBIO.pending and SSLObject.pending values but they can't always reliably tell that we have to wait for more data.\r\n\r\nFor example, it is possible that incoming MemoryBIO.pending \u003e 0, SSLObject.pending == 0. We call SSLObject.read and it throws because incoming MemoryBIO doesn't have the full ssl frame yet.\r\n\r\nExample echo client that replicates internal logic in asyncio/uvloop:\r\n\r\n```python\r\nimport socket\r\nimport ssl\r\nimport select\r\nfrom typing import Optional\r\n\r\nssl_context = ssl.create_default_context()\r\nssl_context.check_hostname = False\r\nssl_context.verify_mode = ssl.CERT_NONE\r\n\r\nep = select.epoll(2)\r\n\r\nincoming = ssl.MemoryBIO()\r\noutgoing = ssl.MemoryBIO()\r\n\r\nsock: Optional[socket.socket] = None\r\nssl_sock: Optional[ssl.SSLObject] = None\r\n\r\n\r\ndef wait_data():\r\n    ep.poll()\r\n\r\n    try:\r\n        while True:\r\n            chunk = sock.recv(1024)\r\n            incoming.write(chunk)\r\n    except BlockingIOError:\r\n        pass\r\n\r\n\r\ndef wait_data_until_ssl_read_succeed():\r\n    data = bytearray()\r\n    try:\r\n        wait_data()\r\n        # while ssl_sock.pending() \u003e 0 or incoming.pending \u003e 0:\r\n        while True:\r\n            data += ssl_sock.read()\r\n    except ssl.SSLWantReadError:\r\n        pass\r\n\r\n    return data\r\n\r\n\r\nwith socket.socket(socket.AF_INET, socket.SOCK_STREAM) as sock:\r\n    ep.register(sock.fileno(), select.EPOLLIN)\r\n\r\n    ssl_sock = ssl_context.wrap_bio(incoming, outgoing, server_hostname='localhost')\r\n\r\n    sock.connect(('127.0.0.1', 25000))\r\n    sock.setblocking(False)\r\n\r\n    handshake_complete = False\r\n    message_sent = False\r\n\r\n    msg = b\"a\" * 256\r\n\r\n    # do handshake\r\n    while True:\r\n        try:\r\n            ssl_sock.do_handshake()\r\n            break\r\n        except ssl.SSLWantReadError as ex:\r\n            if outgoing.pending \u003e 0:\r\n                chunk = outgoing.read(outgoing.pending)\r\n                sock.send(chunk)\r\n            wait_data()\r\n\r\n    # send message and wait for reply\r\n    while True:\r\n        ssl_sock.write(msg)\r\n        chunk = outgoing.read(outgoing.pending)\r\n        sock.send(chunk)\r\n\r\n        data = wait_data_until_ssl_read_succeed()\r\n        # print(data)\r\n```\r\n\r\nPerf output:\r\n```\r\n   17.41%     0.25%            43  python   _ssl.cpython-314-x86_64-linux-gnu.so     [.] _ssl__SSLSocket_read\r\n            |          \r\n             --17.16%--_ssl__SSLSocket_read\r\n                       |          \r\n                       |--8.09%--SSL_read_ex\r\n                       |          |          \r\n                       |           --7.74%--0x7b1fbef883f9\r\n                       |                     |          \r\n                       |                     |--4.83%--0x7b1fbefadc22\r\n                       |                     |          |          \r\n                       |                     |          |--0.93%--0x7b1fbefa6919\r\n                       |                     |          |          |          \r\n                       |                     |          |           --0.90%--EVP_DecryptUpdate\r\n                       |                     |          |                     |          \r\n                       |                     |          |                      --0.90%--0x7b1fbec90c8b\r\n                       |                     |          |                                |          \r\n                       |                     |          |                                 --0.87%--0x7b1fbec90b45\r\n                       |                     |          |          \r\n                       |                     |          |--0.79%--0x7b1fbefa64a5\r\n                       |                     |          |          |          \r\n                       |                     |          |           --0.61%--EVP_CIPHER_CTX_get_iv_length\r\n                       |                     |          |          \r\n                       |                     |          |--0.72%--0x7b1fbefa6721\r\n                       |                     |          |          |          \r\n                       |                     |          |           --0.60%--EVP_CipherInit_ex\r\n                       |                     |          |          \r\n                       |                     |          |--0.57%--0x7b1fbefa6750\r\n                       |                     |          |          \r\n                       |                     |           --0.52%--0x7b1fbefa68f0\r\n                       |                     |          \r\n                       |                     |--1.13%--0x7b1fbefadf94\r\n                       |                     |          |          \r\n                       |                     |           --0.52%--0x7b1fbefac3c7\r\n                       |                     |          \r\n                       |                      --0.68%--0x7b1fbefad750\r\n                       |          \r\n                       |--6.21%--PySSL_SetError.constprop.0\r\n                       |          |          \r\n                       |           --5.17%--fill_and_set_sslerror\r\n                       |                     |          \r\n                       |                     |--2.83%--PyUnicode_FromFormat\r\n                       |                     |          |          \r\n                       |                     |           --2.54%--unicode_from_format\r\n                       |                     |                     |          \r\n                       |                     |                      --1.23%--__sprintf_chk\r\n                       |                     |                                __vsprintf_internal\r\n                       |                     |                                |          \r\n                       |                     |                                 --0.99%--__vfprintf_internal\r\n                       |                     |          \r\n                       |                      --1.01%--PyObject_SetAttr\r\n                       |                                |          \r\n                       |                                 --0.98%--PyObject_GenericSetAttr\r\n                       |                                           |          \r\n                       |                                            --0.52%--_PyObjectDict_SetItem\r\n                       |          \r\n                        --0.60%--SSL_get_error\r\n```\r\n\r\nTo reproduce you would need some ssl echo server running on localhost 25000 port. After you have started it, run echo client code under perf.\r\n\r\n```\r\n$ perf record -F 999 -g --call-graph lbr --user-callchains -- python echo_client.py\r\n$ perf report -G -n --stdio\r\n```\r\nLet it work for 15 seconds and then press Ctrl-C\r\n\r\n\r\n### CPython versions tested on:\r\n\r\nCPython main branch\r\n\r\n### Operating systems tested on:\r\n\r\nLinux\n\n\u003c!-- gh-linked-prs --\u003e\n### Linked PRs\n* gh-128391\n\u003c!-- /gh-linked-prs --\u003e\n","author":{"url":"https://github.com/tarasko","@type":"Person","name":"tarasko"},"datePublished":"2024-09-11T14:24:26.000Z","interactionStatistic":{"@type":"InteractionCounter","interactionType":"https://schema.org/CommentAction","userInteractionCount":12},"url":"https://github.com/123954/cpython/issues/123954"}