[issue36098] asyncio: ssl client-server with "slow" read

[Andrew Svetlov]

Andrew Svetlov  added the comment:

Thanks for checking

--
resolution:  -> fixed
stage:  -> resolved
status: open -> closed

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue36098] asyncio: ssl client-server with "slow" read

[Kumar Aditya]

Kumar Aditya  added the comment:

This has been fixed with bpo-44011 on main branch.

Output on main branch:

--
/workspaces/cpython/main.py:42: DeprecationWarning: There is no current event 
loop
  loop = asyncio.get_event_loop()
received 8192, total 8192
received 8192, total 16384
received 8192, total 24576
received 8192, total 32768
received 8192, total 40960
received 8192, total 49152
received 8192, total 57344
received 8192, total 65536
received 8192, total 73728
received 8192, total 81920
received 8192, total 90112
received 8192, total 98304
received 8192, total 106496
received 8192, total 114688
received 8192, total 122880
received 8192, total 131072
received 8192, total 139264
received 8192, total 147456
received 8192, total 155648
received 8192, total 163840
received 8192, total 172032
received 8192, total 180224
received 8192, total 188416
received 8192, total 196608
received 8192, total 204800
received 8192, total 212992
received 8192, total 221184
received 8192, total 229376
received 8192, total 237568
received 8192, total 245760
received 8192, total 253952
received 8192, total 262144
received 8192, total 270336
received 8192, total 278528
received 8192, total 286720
received 8192, total 294912
received 8192, total 303104
received 8192, total 311296
received 8192, total 319488
received 8192, total 327680
received 8192, total 335872
received 8192, total 344064
received 8192, total 352256
received 8192, total 360448
received 8192, total 368640
received 8192, total 376832
received 8192, total 385024
received 8192, total 393216
received 8192, total 401408
received 8192, total 409600
received 0, total 409600



This can be closed now @asvetlov.

--
nosy: +kumaraditya303

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue36098] asyncio: ssl client-server with "slow" read

[Christian Heimes]

Christian Heimes  added the comment:

The additional read may read the TLS shutdown alert from the wire. The TLS 
record layer can send additional messages besides application layer data, e.g. 
for post handshake authentication, sessions, rekeying, and to indicate that one 
side is shutting down the current TLS connection.

To investigate you can either use the undocumented SSLContext._msg_callback 
debug hook or Wireshark with SSLKEYLOGFILE env var (available since 3.8).

--
nosy: +christian.heimes

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue36098] asyncio: ssl client-server with "slow" read

[Alexander Mohr]

Alexander Mohr  added the comment:

so I did some investigation into the difference between aiohttp + httpx and it 
appears that for some reason httpx does an extra read after the connection is 
closed.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue36098] asyncio: ssl client-server with "slow" read

[Alexander Mohr]

Alexander Mohr  added the comment:

I've updated https://repl.it/@thehesiod/PristineBonyBugs#main.py to contain 
both httpx + aiohttp testcases, and now httpx reproduces almost immediately and 
aiohttp is still ok

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue36098] asyncio: ssl client-server with "slow" read

[Alexander Mohr]

Alexander Mohr  added the comment:

as an FYI I've reproduced this with the httpx library as well: 
https://repl.it/repls/PristineBonyBugs#main.py.  It reproduces on this site but 
I've been unable to reproduce it locally.  It does always reproduce on our 
production systems.

what's interesting is that it I can't seem to be able to reproduce it with 
aiohttp either on that site or locally:
https://repl.it/@thehesiod/PristineBonyBugs-1#main.py

does aiohttp do something to avoid this scenario?

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue36098] asyncio: ssl client-server with "slow" read

[J. Nick Koston]

Change by J. Nick Koston :


--
nosy: +bdraco

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue36098] asyncio: ssl client-server with "slow" read

[Alexander Mohr]

Change by Alexander Mohr :


--
nosy: +thehesiod

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue36098] asyncio: ssl client-server with "slow" read

[Andrew Svetlov]

Andrew Svetlov  added the comment:

Thanks for the report.

We definitely have to fix `AttributeError`.
Unfortunately, SSL implementation in asyncio is very tricky.

Yuri has an experimental asyncio ssl replacement in his uvloop project 
rewritten from scratch.
There is a plan to port it into asyncio itself.

P.S.
`await writer.drain()` doesn't send all data to buffer but ensures that the 
write buffer size is below high watermark limit 
(https://docs.python.org/3/library/asyncio-protocol.html#asyncio.WriteTransport.set_write_buffer_limits)

Actually, it is good. Even after pushing a data into socket buffer you have no 
knowledge when the data is delivered to peer (or maybe not delivered at all at 
the moment of socket closing).
Moreover, when I experimented with write buffer disabling 
(transport.set_write_buffer_limits(1)) in aiohttp server benchmarks was 
executed about 50% slower for simple 'ping' request.

--

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

[issue36098] asyncio: ssl client-server with "slow" read

[MultiSosnooley]

New submission from MultiSosnooley :

Recently, some awesome contributors add support for implicit ssl mode for 
aioftp. But this produced some issues and one of them is not relevant to 
aioftp, but to asyncio. Here is link 
https://repl.it/@multisosnooley/asyncio-ssl-connection-with-slow-retreiving to 
reproduce. This code mimics one test of aioftp: filesystem slower, than socket 
write. Reduced code to reproduce use sleep for this purpose. So we have proper 
run without ssl (you can test this by removing ssl argument in server and 
client instantiation) and «buggy» in case of ssl. After some digging in I 
realised, that someone calls connection_lost of ssl protocol before we read all 
data from transport. Data sent by server, but client have (looks like 64k) 
buffer and since there is no transport read fails. Also, I can say (with help 
of wireshark) that in case of non-ssl connection, tcp FIN initiated by server 
(as it should be), but in case of ssl — FIN sent by client.

Direct code to reproduce
```
import ssl
import asyncio

import trustme


HOST = "127.0.0.1"
PORT = 8021

ca = trustme.CA()
server_cert = ca.issue_server_cert(HOST)

ssl_server = ssl.create_default_context(ssl.Purpose.CLIENT_AUTH)
server_cert.configure_cert(ssl_server)

ssl_client = ssl.create_default_context(ssl.Purpose.SERVER_AUTH)
ca.configure_trust(ssl_client)


async def handler(reader, writer):
writer.write(b"0" * 4 * 100 * 1024)
await writer.drain()
writer.close()
await asyncio.sleep(1)
print("handler done")


async def client():
# reader, writer = await asyncio.open_connection(HOST, PORT)
reader, writer = await asyncio.open_connection(HOST, PORT, ssl=ssl_client)
count = 0
while True:
data = await reader.read(8192)
count += len(data)
print(f"received {len(data)}, total {count}")
if not data:
break
await asyncio.sleep(0.001)
writer.close()


loop = asyncio.get_event_loop()
# start = asyncio.start_server(handler, HOST, PORT)
start = asyncio.start_server(handler, HOST, PORT, ssl=ssl_server)
server = loop.run_until_complete(start)
loop.run_until_complete(client())
server.close()
loop.run_until_complete(server.wait_closed())
```

Output:
```
received 8192, total 8192
received 8192, total 16384
received 8192, total 24576
received 8192, total 32768
received 8192, total 40960
received 8192, total 49152
received 8192, total 57344
received 8192, total 65536
received 8192, total 73728
received 8192, total 81920
received 8192, total 90112
received 8192, total 98304
received 8192, total 106496
received 8192, total 114688
received 8192, total 122880
received 8192, total 131072
received 8192, total 139264
received 8192, total 147456
received 8192, total 155648
received 8192, total 163840
received 8192, total 172032
received 8192, total 180224
received 8192, total 188416
received 8192, total 196608
received 8192, total 204800
received 8192, total 212992
received 8192, total 221184
received 8192, total 229376
received 8192, total 237568
received 8192, total 245760
received 8192, total 253952
received 8192, total 262144
received 8192, total 270336
received 8192, total 278528
received 8192, total 286720
received 8192, total 294912
received 8192, total 303104
received 8192, total 311296
received 8192, total 319488
received 8192, total 327680
received 8192, total 335872
Traceback (most recent call last):
  File "slow-data-test.py", line 46, in 
loop.run_until_complete(client())
  File "/home/poh/.pyenv/versions/3.6.7/lib/python3.6/asyncio/base_events.py", 
line 473, in run_until_complete
return future.result()
  File "slow-data-test.py", line 33, in client
data = await reader.read(8192)
  File "/home/poh/.pyenv/versions/3.6.7/lib/python3.6/asyncio/streams.py", line 
640, in read
self._maybe_resume_transport()
  File "/home/poh/.pyenv/versions/3.6.7/lib/python3.6/asyncio/streams.py", line 
408, in _maybe_resume_transport
self._transport.resume_reading()
  File "/home/poh/.pyenv/versions/3.6.7/lib/python3.6/asyncio/sslproto.py", 
line 351, in resume_reading
self._ssl_protocol._transport.resume_reading()
AttributeError: 'NoneType' object has no attribute 'resume_reading'
```

--
components: asyncio
messages: 336420
nosy: MultiSosnooley, asvetlov, yselivanov
priority: normal
severity: normal
status: open
title: asyncio: ssl client-server with "slow" read
type: behavior
versions: Python 3.6, Python 3.7, Python 3.8

___
Python tracker 

___
___
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com