Issue39951
This issue tracker has been migrated to GitHub,
and is currently read-only.
For more information,
see the GitHub FAQs in the Python's Developer Guide.
Created on 2020-03-13 03:40 by Dima.Tisnek, last changed 2022-04-11 14:59 by admin. This issue is now closed.
Messages (13) | |||
---|---|---|---|
msg364071 - (view) | Author: Dima Tisnek (Dima.Tisnek) * | Date: 2020-03-13 03:40 | |
When a connection wrapped in ssl is closed, sometimes the ssl library reports an error, which I believe should be ignored. The error code is `291` and the name of the error is either SSL_R_KRB5_S_INIT (KRB5_S_INIT) or SSL_R_APPLICATION_DATA_AFTER_CLOSE_NOTIFY depending on openssl header file. It's only one code, somehow `ssl.h` (depending on version?) has different symbolic name for the error. TBH, I consider `KRB5_S_INIT` a misnomer, there's no Kerberos here. The explanation for openssl reporting this error is here: https://github.com/openssl/openssl/blob/6d53ad6b5cf726d92860e973d7bc8c1930762086/ssl/record/rec_layer_s3.c#L1657-L1668 > The peer is continuing to send application data, but we have > already sent close_notify. If this was expected we should have > been called via SSL_read() and this would have been handled > above. This situation is easily achieved, because of network delays. Just because we sent "close notify", doesn't mean the other end has received it, and even if it did, there could still be return data in flight. Reproducer is here: https://gist.github.com/dimaqq/087c66dd7b4a85a669a00221dc3792ea |
|||
msg364073 - (view) | Author: Dima Tisnek (Dima.Tisnek) * | Date: 2020-03-13 03:52 | |
Reproducer: """ Reproducer for BPO-39951 We send some data over ssl and close the connection. The server responds after our openssl considers the connection closed-ish and raises an error. """ import asyncio import ssl host = "nghttp2.org" port = 443 ssl_context = ssl.create_default_context() ssl_context.options |= ssl.OP_NO_TLSv1 ssl_context.options |= ssl.OP_NO_TLSv1_1 ssl_context.set_alpn_protocols(["h2"]) # Captured from an HTTP/2 client DATA = b'PRI * HTTP/2.0\r\n\r\nSM\r\n\r\n\x00\x00*\x04\x00\x00\x00\x00\x00\x00\x01\x00\x00\x10\x00\x00\x02\x00\x00\x00\x00\x00\x04\x00\x00\xff\xff\x00\x05\x00\x00@\x00\x00\x08\x00\x00\x00\x00\x00\x03\x00\x10\x00\x00\x00\x06\x00\x00\xff\xff\x00\x00\x04\x08\x00\x00\x00\x00\x00\x01\x00\x00\x00\x00\x00\x00\x04\x01\x00\x00\x00\x00' async def test(): r, w = await asyncio.open_connection(host, port, ssl=ssl_context) info = w.get_extra_info("ssl_object") assert info, "HTTP/2 server is required" proto = info.selected_alpn_protocol() assert proto == "h2", "Failed to negotiate HTTP/2" w.write(DATA) w.close() await w.wait_closed() asyncio.run(test()) Test on macOS, using cpython builds from python.org: … > python3.7 repro-bpo-39951.py Traceback (most recent call last): File "repro-bpo-39951.py", line 34, in <module> asyncio.run(test()) File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/runners.py", line 43, in run return loop.run_until_complete(main) File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/base_events.py", line 579, in run_until_complete return future.result() File "repro-bpo-39951.py", line 31, in test await w.wait_closed() File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/streams.py", line 323, in wait_closed await self._protocol._closed File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/sslproto.py", line 530, in data_received ssldata, appdata = self._sslpipe.feed_ssldata(data) File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/asyncio/sslproto.py", line 207, in feed_ssldata self._sslobj.unwrap() File "/Library/Frameworks/Python.framework/Versions/3.7/lib/python3.7/ssl.py", line 778, in unwrap return self._sslobj.shutdown() ssl.SSLError: [SSL: KRB5_S_INIT] application data after close notify (_ssl.c:2629) … > python3.8 repro-bpo-39951.py Traceback (most recent call last): File "repro-bpo-39951.py", line 34, in <module> asyncio.run(test()) File "/Library/Frameworks/Python.framework/Versions/3.8/lib/python3.8/asyncio/runners.py", line 43, in run return loop.run_until_complete(main) File "/Library/Frameworks/Python.framework/Versions/3.8/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete return future.result() File "repro-bpo-39951.py", line 31, in test await w.wait_closed() File "/Library/Frameworks/Python.framework/Versions/3.8/lib/python3.8/asyncio/streams.py", line 359, in wait_closed await self._protocol._get_close_waiter(self) File "/Library/Frameworks/Python.framework/Versions/3.8/lib/python3.8/asyncio/sslproto.py", line 529, in data_received ssldata, appdata = self._sslpipe.feed_ssldata(data) File "/Library/Frameworks/Python.framework/Versions/3.8/lib/python3.8/asyncio/sslproto.py", line 207, in feed_ssldata self._sslobj.unwrap() File "/Library/Frameworks/Python.framework/Versions/3.8/lib/python3.8/ssl.py", line 948, in unwrap return self._sslobj.shutdown() ssl.SSLError: [SSL: KRB5_S_INIT] application data after close notify (_ssl.c:2730) … > python3.9 repro-bpo-39951.py Traceback (most recent call last): File "/.../repro-bpo-39951.py", line 34, in <module> asyncio.run(test()) File "/Library/Frameworks/Python.framework/Versions/3.9/lib/python3.9/asyncio/runners.py", line 43, in run return loop.run_until_complete(main) File "/Library/Frameworks/Python.framework/Versions/3.9/lib/python3.9/asyncio/base_events.py", line 642, in run_until_complete return future.result() File "/.../repro-bpo-39951.py", line 31, in test await w.wait_closed() File "/Library/Frameworks/Python.framework/Versions/3.9/lib/python3.9/asyncio/streams.py", line 359, in wait_closed await self._protocol._get_close_waiter(self) File "/Library/Frameworks/Python.framework/Versions/3.9/lib/python3.9/asyncio/sslproto.py", line 529, in data_received ssldata, appdata = self._sslpipe.feed_ssldata(data) File "/Library/Frameworks/Python.framework/Versions/3.9/lib/python3.9/asyncio/sslproto.py", line 207, in feed_ssldata self._sslobj.unwrap() File "/Library/Frameworks/Python.framework/Versions/3.9/lib/python3.9/ssl.py", line 948, in unwrap return self._sslobj.shutdown() ssl.SSLError: [SSL: KRB5_S_INIT] application data after close notify (_ssl.c:2730) Test on Linux (python:3.8.1-alpine3.11): / # python repro.py Traceback (most recent call last): File "repro.py", line 33, in <module> asyncio.run(test()) File "/usr/local/lib/python3.8/asyncio/runners.py", line 43, in run return loop.run_until_complete(main) File "/usr/local/lib/python3.8/asyncio/base_events.py", line 612, in run_until_complete return future.result() File "repro.py", line 30, in test await w.wait_closed() File "/usr/local/lib/python3.8/asyncio/streams.py", line 359, in wait_closed await self._protocol._get_close_waiter(self) File "/usr/local/lib/python3.8/asyncio/sslproto.py", line 529, in data_received ssldata, appdata = self._sslpipe.feed_ssldata(data) File "/usr/local/lib/python3.8/asyncio/sslproto.py", line 207, in feed_ssldata self._sslobj.unwrap() File "/usr/local/lib/python3.8/ssl.py", line 948, in unwrap return self._sslobj.shutdown() ssl.SSLError: [SSL: KRB5_S_INIT] application data after close notify (_ssl.c:2730) |
|||
msg365293 - (view) | Author: Dima Tisnek (Dima.Tisnek) * | Date: 2020-03-30 03:02 | |
Let's close this in favour of https://bugs.python.org/issue39953 which has a pending pull request https://github.com/python/cpython/pull/19082 |
|||
msg365299 - (view) | Author: Dima Tisnek (Dima.Tisnek) * | Date: 2020-03-30 05:29 | |
Sorry I was too fast to close this. 39953 is about error codes. This bug is about having an error at all. I believe that the code in question should pass without error, even in the presence of network delays. |
|||
msg379902 - (view) | Author: Dima Tisnek (Dima.Tisnek) * | Date: 2020-10-30 01:12 | |
https://bugs.python.org/issue39953 has landed and the errors are now more sensible: (that patch was not backported to 3.7, because it's not a security issue). Python 3.7.8 [SSL: KRB5_S_INIT] application data after close notify Python 3.8.5 [SSL: APPLICATION_DATA_AFTER_CLOSE_NOTIFY] application data after close notify Python 3.9.0 [SSL: APPLICATION_DATA_AFTER_CLOSE_NOTIFY] application data after close notify Python 3.10.0a1 [SSL: APPLICATION_DATA_AFTER_CLOSE_NOTIFY] application data after close notify I guess I shall work on a patch to ignore this specific error when closing the connection. I would appreciate guidance on half-closed state that, it seems, is possible since TLS 1.3 🤔 |
|||
msg386513 - (view) | Author: Fantix King (fantix) * | Date: 2021-02-05 05:21 | |
This should/will be fixed by GH-17975 I think - like suggested in the OpenSSL comments, the proposed change will always try to run SSL_read() before SSL_shutdown(), even after the close_notify is sent. |
|||
msg386514 - (view) | Author: Dima Tisnek (Dima.Tisnek) * | Date: 2021-02-05 07:44 | |
@fantix alas, no: ~/cpython (asvetlov--new-ssl|✚1) [1] > ./python.exe ~/repro-39951.py Traceback (most recent call last): File "/Users/dima.tisnek/repro-39951.py", line 33, in <module> asyncio.run(test()) File "/Users/dima.tisnek/cpython/Lib/asyncio/runners.py", line 43, in run return loop.run_until_complete(main) File "/Users/dima.tisnek/cpython/Lib/asyncio/base_events.py", line 642, in run_until_complete return future.result() File "/Users/dima.tisnek/repro-39951.py", line 30, in test await w.wait_closed() File "/Users/dima.tisnek/cpython/Lib/asyncio/streams.py", line 359, in wait_closed await self._protocol._get_close_waiter(self) File "/Users/dima.tisnek/cpython/Lib/asyncio/sslproto.py", line 638, in _do_shutdown self._sslobj.unwrap() File "/Users/dima.tisnek/cpython/Lib/ssl.py", line 948, in unwrap return self._sslobj.shutdown() ssl.SSLError: [SSL: KRB5_S_INIT] application data after close notify (_ssl.c:2730) |
|||
msg386515 - (view) | Author: Dima Tisnek (Dima.Tisnek) * | Date: 2021-02-05 07:45 | |
Added 3.10 target. |
|||
msg386516 - (view) | Author: Christian Heimes (christian.heimes) * ![]() |
Date: 2021-02-05 08:08 | |
3.7 is in security fix-only mode. APPLICATION_DATA_AFTER_CLOSE_NOTIFY is a protocol violation in any TLS version. It's not related to TLS 1.3. The error occurs when one side wants to close the connection, but the other sides keeps sending user data. It's bug in higher level application could. The ssl module cannot ignore this error condition. https://github.com/openssl/openssl/blob/76624df15fef0725f28a8b9d0f31256946669b1a/ssl/record/rec_layer_s3.c#L1635-L1648 |
|||
msg386518 - (view) | Author: Dima Tisnek (Dima.Tisnek) * | Date: 2021-02-05 08:29 | |
Thank you, Christian, for removing 3.7 target, I was not up to date on Python support schedule. Regarding protocol violation, let me explain what I've dug up so far... I am not an expert, please feel free to correct me. TLS up to 1.2 Closing a connection (sending close notifies) closes both directions at once. However, something like a data race is possible: Let's say "our" side sent close notify at t0, which arrives at "their" side at t1, and the packet that "their" sent at "t1" arrives back to "us" at t2. "Their" side can legitimately continue to send data during t0..t1, as it has not received the close notify yet. This data can arrive at "our" side anywhere within t0...t2 period. Current implementation treats this data as protocol violation. I don't believe it should, because the data was legitimate at the time it was sent. It should most likely be discarded though. TLS 1.3 and later Closing a connection only closes one half of the connection, the other half is closed after the round trip. (I'm not clear whether that's always the case, or if that's an option). Current implementation is simply unprepared for half-closed connections (I think) and thus in a way, unprepared for TLS 1.3 |
|||
msg386520 - (view) | Author: Christian Heimes (christian.heimes) * ![]() |
Date: 2021-02-05 10:08 | |
TLS 1.2 has one-way close notify. For example typical HTTP clients like curl send a close_notify and then shut down the TCP connection. HTTP servers may not reply with close_notify or may not wait for the client to confirm the server-side close notify. Python's ssl module does not support one-way close yet. It's an unfortunate limitation of the API that predates my involvement in the ssl module. The unwrap() methods always performs a blocking two-way shutdown. unwrap() calls SSL_shutdown() twice to downgrade a TLS connection to a plain TCP connection. The unwrap() API also requires cooperation from both parties. https://tools.ietf.org/html/rfc5246#section-7.2.1 https://www.openssl.org/docs/manmaster/man3/SSL_shutdown.html |
|||
msg414794 - (view) | Author: Kumar Aditya (kumaraditya) * ![]() |
Date: 2022-03-09 12:00 | |
@asvetlov This has been fixed on main branch with bpo-44011. This can be closed now. |
|||
msg414798 - (view) | Author: Christian Heimes (christian.heimes) * ![]() |
Date: 2022-03-09 12:20 | |
The bug should be fixed in 3.9 and 3.10 maintenance branches, too. |
History | |||
---|---|---|---|
Date | User | Action | Args |
2022-04-11 14:59:28 | admin | set | github: 84132 |
2022-03-12 14:03:27 | asvetlov | set | status: open -> closed resolution: fixed stage: backport needed -> resolved |
2022-03-09 12:20:13 | christian.heimes | set | assignee: christian.heimes -> stage: backport needed messages: + msg414798 versions: + Python 3.9, Python 3.10 |
2022-03-09 12:00:16 | kumaraditya | set | nosy:
+ kumaraditya messages: + msg414794 versions: + Python 3.11, - Python 3.8, Python 3.9, Python 3.10 |
2021-02-05 10:08:33 | christian.heimes | set | messages: + msg386520 |
2021-02-05 08:29:23 | Dima.Tisnek | set | messages: + msg386518 |
2021-02-05 08:08:37 | christian.heimes | set | assignee: christian.heimes type: behavior components: + asyncio, SSL, - Extension Modules, Library (Lib) versions: - Python 3.7 nosy: + yselivanov, asvetlov messages: + msg386516 stage: resolved -> (no value) |
2021-02-05 07:45:15 | Dima.Tisnek | set | messages:
+ msg386515 versions: + Python 3.10 |
2021-02-05 07:44:45 | Dima.Tisnek | set | messages: + msg386514 |
2021-02-05 05:21:11 | fantix | set | nosy:
+ fantix messages: + msg386513 |
2020-10-30 01:12:52 | Dima.Tisnek | set | messages: + msg379902 |
2020-04-11 21:17:43 | SilentGhost | set | nosy:
+ christian.heimes |
2020-03-30 05:29:51 | Dima.Tisnek | set | status: closed -> open resolution: duplicate -> (no value) messages: + msg365299 |
2020-03-30 03:02:32 | Dima.Tisnek | set | status: open -> closed resolution: duplicate messages: + msg365293 stage: resolved |
2020-03-13 03:52:10 | Dima.Tisnek | set | messages:
+ msg364073 versions: + Python 3.7 |
2020-03-13 03:40:01 | Dima.Tisnek | create |