Issue 29406: asyncio SSL contexts leak sockets after calling close with certain Apache servers (original) (raw)

process

Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: asvetlov Nosy List: Dima.Tisnek, Mariatta, asvetlov, christian.heimes, fafhrd, fafhrd91, grzgrzgrz3, kumaraditya, lukasz.langa, ned.deily, rthr, thehesiod, yselivanov
Priority: critical Keywords: patch

Created on 2017-02-01 00:39 by thehesiod, last changed 2022-04-11 14:58 by admin. This issue is now closed.

Files
File name Uploaded Description Edit
scratch_1.py thehesiod,2017-02-01 00:42 asyncio SSL socket leak after close
ssl_shutdown_timeout.patch fafhrd91,2017-02-01 04:35
Pull Requests
URL Status Linked Edit
PR 409 merged fafhrd91,2017-03-03 23:25
PR 981 merged misg,2017-04-03 17:11
PR 2062 merged yselivanov,2017-06-10 04:08
PR 2063 merged yselivanov,2017-06-10 04:10
PR 2111 merged yselivanov,2017-06-11 14:17
PR 2112 merged yselivanov,2017-06-11 14:20
PR 2113 merged yselivanov,2017-06-11 14:27
PR 2269 closed fafhrd91,2017-06-18 21:45
PR 4402 closed asvetlov,2017-11-15 10:29
Messages (37)
msg286573 - (view) Author: Alexander Mohr (thehesiod) * Date: 2017-02-01 00:39
with the attached code note how HttpClient.connection_lost callback is never called for the madis server. The madis server is an apache server, I tried with the OSX apache server and could not reproduce the issue so it seems something particular about their apache version or configuration. This is a pretty critical issue as close() does not release the socket.
msg286574 - (view) Author: Alexander Mohr (thehesiod) * Date: 2017-02-01 00:42
updating to make default the error case (madis)
msg286586 - (view) Author: Nikolay Kim (fafhrd91) * Date: 2017-02-01 04:35
madis-data.ncep.noaa.gov side does not complete ssl shutdown process.
msg286664 - (view) Author: Alexander Mohr (thehesiod) * Date: 2017-02-01 17:22
Thanks so much for the patch! may want to change spelling of what was supposed to be "shutdown" =) Also think it's worth a comment stating why it's needed? Like certain Apache servers were noticed to not complete the SSL shutdown process.
msg288841 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2017-03-02 23:48
Can you guys create a PR on github.com/python/cpython?
msg295588 - (view) Author: Mariatta (Mariatta) * (Python committer) Date: 2017-06-09 22:14
There are two PRs for this issue. Is one depending on the other? PR 409 has merge conflict that needs to be resolved.
msg295589 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2017-06-09 22:25
> There are two PRs for this issue. Is one depending on the other? No, they all address slightly different bugs. All need to be merged though. > PR 409 has merge conflict that needs to be resolved. Yes, it seems that it's based on 3.6 branch. I asked the author to rebase it.
msg295605 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2017-06-10 04:04
New changeset a608d2d5a7f1aabe9bcbfc220135c5e126189390 by Yury Selivanov (Nikolay Kim) in branch 'master': bpo-29406: asyncio SSL contexts leak sockets after calling close with certain servers (#409) https://github.com/python/cpython/commit/a608d2d5a7f1aabe9bcbfc220135c5e126189390
msg295636 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2017-06-10 14:00
New changeset 6e14fd2a14cef6ea0709ad234ab41198c2195591 by Yury Selivanov in branch '3.6': [3.6] bpo-29406: asyncio SSL contexts leak sockets after calling close with certain servers (GH-409) (#2062) https://github.com/python/cpython/commit/6e14fd2a14cef6ea0709ad234ab41198c2195591
msg295637 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2017-06-10 14:01
New changeset 1395c58ef7b98f087d1d5d50962fe7a8c032f34d by Yury Selivanov in branch '3.5': [3.5] bpo-29406: asyncio SSL contexts leak sockets after calling close with certain servers (GH-409) (#2063) https://github.com/python/cpython/commit/1395c58ef7b98f087d1d5d50962fe7a8c032f34d
msg295659 - (view) Author: Ned Deily (ned.deily) * (Python committer) Date: 2017-06-10 19:31
While testing current 3.6 top of trunk, I noticed spurious error messages being reported that were not causing the tests to fail. Investigating further, I found the culprit to be this issue's 6e14fd2a14cef6ea0709ad234ab41198c2195591. Curiously, the errors aren't showing up on buildbots although I can reproduce 100% on both platforms I've tried: Debian Linux and macOS 10.12. For some reason that needs to be explored, using -W on regrtest causes the messages to be suppressed and the buildbots use -w by default. $ ./python Python 3.6.1+ (remotes/upstream/3.6:76eabd3a21, Jun 10 2017, 15:20:44) [GCC 6.3.0 20170516] on linux Type "help", "copyright", "credits" or "license" for more information. >>> # without -w or -W $ ./python -m test test_asyncio Run tests sequentially 0:00:00 [1/1] test_asyncio Fatal error on SSL transport protocol: <asyncio.sslproto.SSLProtocol object at 0xb55423b4> transport: None Traceback (most recent call last): File "/py/3x/unix/source/Lib/asyncio/sslproto.py", line 660, in _process_write_backlog self._transport.write(chunk) AttributeError: 'NoneType' object has no attribute 'write' Fatal error on SSL transport protocol: <asyncio.sslproto.SSLProtocol object at 0xb5542504> transport: None Traceback (most recent call last): File "/py/3x/unix/source/Lib/asyncio/sslproto.py", line 660, in _process_write_backlog self._transport.write(chunk) AttributeError: 'NoneType' object has no attribute 'write' Fatal error on SSL transport protocol: <asyncio.sslproto.SSLProtocol object at 0xb639f8bc> transport: None Traceback (most recent call last): File "/py/3x/unix/source/Lib/asyncio/sslproto.py", line 660, in _process_write_backlog self._transport.write(chunk) AttributeError: 'NoneType' object has no attribute 'write' Fatal error on SSL transport protocol: <asyncio.sslproto.SSLProtocol object at 0xb6126f84> transport: None Traceback (most recent call last): File "/py/3x/unix/source/Lib/asyncio/sslproto.py", line 660, in _process_write_backlog self._transport.write(chunk) AttributeError: 'NoneType' object has no attribute 'write' Fatal error on SSL transport protocol: <asyncio.sslproto.SSLProtocol object at 0xb6392fbc> transport: None Traceback (most recent call last): File "/py/3x/unix/source/Lib/asyncio/sslproto.py", line 660, in _process_write_backlog self._transport.write(chunk) AttributeError: 'NoneType' object has no attribute 'write' Fatal error on SSL transport protocol: <asyncio.sslproto.SSLProtocol object at 0xb671dedc> transport: None Traceback (most recent call last): File "/py/3x/unix/source/Lib/asyncio/sslproto.py", line 660, in _process_write_backlog self._transport.write(chunk) AttributeError: 'NoneType' object has no attribute 'write' 1 test OK. Total duration: 13 sec Tests result: SUCCESS # with -w $ ./python -m test -w test_asyncio Run tests sequentially 0:00:00 [1/1] test_asyncio Fatal error on SSL transport protocol: <asyncio.sslproto.SSLProtocol object at 0xb4b15b5c> transport: None Traceback (most recent call last): File "/py/3x/unix/source/Lib/asyncio/sslproto.py", line 660, in _process_write_backlog self._transport.write(chunk) AttributeError: 'NoneType' object has no attribute 'write' Fatal error on SSL transport protocol: <asyncio.sslproto.SSLProtocol object at 0xb581f264> transport: None Traceback (most recent call last): File "/py/3x/unix/source/Lib/asyncio/sslproto.py", line 660, in _process_write_backlog self._transport.write(chunk) AttributeError: 'NoneType' object has no attribute 'write' Fatal error on SSL transport protocol: <asyncio.sslproto.SSLProtocol object at 0xb53f068c> transport: None Traceback (most recent call last): File "/py/3x/unix/source/Lib/asyncio/sslproto.py", line 660, in _process_write_backlog self._transport.write(chunk) AttributeError: 'NoneType' object has no attribute 'write' Fatal error on SSL transport protocol: <asyncio.sslproto.SSLProtocol object at 0xb65faf14> transport: None Traceback (most recent call last): File "/py/3x/unix/source/Lib/asyncio/sslproto.py", line 660, in _process_write_backlog self._transport.write(chunk) AttributeError: 'NoneType' object has no attribute 'write' Fatal error on SSL transport protocol: <asyncio.sslproto.SSLProtocol object at 0xb5816c04> transport: None Traceback (most recent call last): File "/py/3x/unix/source/Lib/asyncio/sslproto.py", line 660, in _process_write_backlog self._transport.write(chunk) AttributeError: 'NoneType' object has no attribute 'write' Fatal error on SSL transport protocol: <asyncio.sslproto.SSLProtocol object at 0xb582dea4> transport: None Traceback (most recent call last): File "/py/3x/unix/source/Lib/asyncio/sslproto.py", line 660, in _process_write_backlog self._transport.write(chunk) AttributeError: 'NoneType' object has no attribute 'write' 1 test OK. Total duration: 13 sec Tests result: SUCCESS # with -W -> no messages $ ./python -m test -W test_asyncio Run tests sequentially 0:00:00 [1/1] test_asyncio 1 test OK. Total duration: 13 sec Tests result: SUCCESS
msg295660 - (view) Author: Ned Deily (ned.deily) * (Python committer) Date: 2017-06-10 19:32
Er, "For some reason that needs to be explored, using -W on regrtest causes the messages to be suppressed and the buildbots use -w by default." That should be "use -W by default".
msg295661 - (view) Author: Ned Deily (ned.deily) * (Python committer) Date: 2017-06-10 19:39
FTR, same behavior with master (3.7) top of trunk.
msg295670 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2017-06-10 21:14
Nikolay, can you please take a look?
msg295671 - (view) Author: Nikolay Kim (fafhrd91) * Date: 2017-06-10 21:18
yes, i am on it
msg295690 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2017-06-11 07:36
> yes, i am on it Nick, have you been able to find what the problem is? If not, we'll need to pull this change out of 3.6.2.
msg295691 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2017-06-11 07:57
> > yes, i am on it > Nick, have you been able to find what the problem is? If not, we'll need to pull this change out of 3.6.2. It's interesting to see how `_process_write_backlog` gets called after `_finalize`. One option would be to simply guard `transport.write` with `if transport is not None`, but I'm afraid that we'll only mask the bug then.
msg295692 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2017-06-11 07:58
> It's interesting to see how `_process_write_backlog` gets called after `_finalize`. One option would be to simply guard `transport.write` with `if transport is not None`, but I'm afraid that we'll only mask the bug then. OTOH we weren't setting the transport to None before, we were just closing it. Is setting it to None really necessary?
msg295714 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2017-06-11 14:28
Alright, let's play it safe. I'm going to be reverting the change from all branches. Nick, if you are able to figure this out please create a new PR.
msg295715 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2017-06-11 14:46
New changeset 09663de203396b28483a570bb268c130b59639cf by Yury Selivanov in branch 'master': Revert "bpo-29406: asyncio SSL contexts leak sockets after calling close with certain servers (#409)" (#2111) https://github.com/python/cpython/commit/09663de203396b28483a570bb268c130b59639cf
msg295716 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2017-06-11 14:46
New changeset 83d30bd667924549bacf1428ac3e475cdf9792ae by Yury Selivanov in branch '3.6': Revert "[3.6] bpo-29406: asyncio SSL contexts leak sockets after calling close with certain servers (GH-409) (#2062)" (#2112) https://github.com/python/cpython/commit/83d30bd667924549bacf1428ac3e475cdf9792ae
msg295717 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2017-06-11 14:46
New changeset 4e9dfe214dff000c5b5ad0d8bd8a393feed1d3cf by Yury Selivanov in branch '3.5': Revert "[3.5] bpo-29406: asyncio SSL contexts leak sockets after calling close with certain servers (GH-409) (#2063)" (#2113) https://github.com/python/cpython/commit/4e9dfe214dff000c5b5ad0d8bd8a393feed1d3cf
msg295765 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2017-06-12 10:43
See also issue 29970.
msg296359 - (view) Author: Grzegorz Grzywacz (grzgrzgrz3) * Date: 2017-06-19 17:21
This is not problem with madis-data.ncep.noaa.gov not doing ssl shutdown, this is problem with asyncio not doing it. Patch from this #30698 issue fix this too.
msg296360 - (view) Author: Nikolay Kim (fafhrd) Date: 2017-06-19 17:24
Let’s close this issue then. I don’t like it anyway. > On Jun 19, 2017, at 10:21 AM, Grzegorz Grzywacz <report@bugs.python.org> wrote: > > > Grzegorz Grzywacz added the comment: > > This is not problem with madis-data.ncep.noaa.gov not doing ssl shutdown, this is problem with asyncio not doing it. > > Patch from this #30698 issue fix this too. > > ---------- > nosy: +grzgrzgrz3 > > _______________________________________ > Python tracker <report@bugs.python.org> > <http://bugs.python.org/issue29406> > _______________________________________
msg297493 - (view) Author: Ned Deily (ned.deily) * (Python committer) Date: 2017-07-01 18:41
Yury, based on the most recent comments, can this issue be closed now?
msg297678 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2017-07-04 16:49
> Yury, based on the most recent comments, can this issue be closed now? Not sure, I'm reviewing the patch for #30698, let's see if it fixes the problem.
msg302985 - (view) Author: Łukasz Langa (lukasz.langa) * (Python committer) Date: 2017-09-25 23:01
This is marked as Critical so either we should change the priority or fix it soon :)
msg306228 - (view) Author: Andrew Svetlov (asvetlov) * (Python committer) Date: 2017-11-14 17:26
I'm picking up the issue. Will provide an updated PR soon.
msg306230 - (view) Author: Andrew Svetlov (asvetlov) * (Python committer) Date: 2017-11-14 17:31
I'm skeptical about `critical` priority. The bugfix could be backported to Python 3.6 but I very not sure about the need for 3.5. It is a desirable fix but not secure. Yury Selivanov please confirm.
msg306232 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2017-11-14 17:44
> The bugfix could be backported to Python 3.6 but I very not sure about the need for 3.5. > It is a desirable fix but not secure. The attached script looks very innocent, and it's worrisome that it's that easy to make an asyncio SSL server to leak sockets in some contexts. I think it's OK to fix 3.5, but let's make the final decision when we have an approved PR. I merged Nick's PR once, but then it introduced some problems on buildbots (https://bugs.python.org/msg295659), so I reverted the commit. I'd suggest to look at the attached script again (scratch_1.py) and try to understand what exactly causes the problem with that specific Apache server version. I'd also suggest to come up with a *functional* unittest that reproduces it (you can grab some testing utilities from the uvloop project).
msg309822 - (view) Author: Alexander Mohr (thehesiod) * Date: 2018-01-11 18:54
my understanding is that the PR in https://bugs.python.org/issue30698 fixes this issue no? If so can we get it merged?
msg312892 - (view) Author: Christian Heimes (christian.heimes) * (Python committer) Date: 2018-02-26 08:36
Andrew, Yury, PR 4402 is still open. Should the fix land in 3.7? I have removed the SSL component because it's not a bug in the ssl module.
msg312916 - (view) Author: Andrew Svetlov (asvetlov) * (Python committer) Date: 2018-02-26 11:13
I'll take a look on the evening
msg332042 - (view) Author: Dima Tisnek (Dima.Tisnek) * Date: 2018-12-18 06:41
ping...
msg332074 - (view) Author: Yury Selivanov (yselivanov) * (Python committer) Date: 2018-12-18 18:34
Dima, we'll likely address this in 3.8, when we land new SSL implementation. Meanwhile you can use uvloop where all these bugs should be fixed.
msg414509 - (view) Author: Kumar Aditya (kumaraditya) * (Python triager) Date: 2022-03-04 08:42
Since bpo-issue44011 is fixed, this can be closed now @asvetlov.
History
Date User Action Args
2022-04-11 14:58:42 admin set github: 73592
2022-03-14 22:50:24 asvetlov set status: open -> closedstage: patch review -> resolvedresolution: fixedversions: + Python 3.11, - Python 3.6, Python 3.7, Python 3.8
2022-03-04 09:43:52 vstinner set nosy: - vstinner
2022-03-04 08:42:03 kumaraditya set nosy: + kumaradityamessages: +
2018-12-18 18:34:33 yselivanov set messages: +
2018-12-18 18:23:50 gvanrossum set nosy: - gvanrossum
2018-12-18 06:41:12 Dima.Tisnek set nosy: + Dima.Tisnekmessages: +
2018-02-26 11:13:25 asvetlov set messages: +
2018-02-26 08:36:41 christian.heimes set versions: + Python 3.8, - Python 3.5nosy: + christian.heimesmessages: + components: - SSL
2018-01-18 00:49:57 Angie G set type: resource usage -> performancecomponents: + Build, SSL
2018-01-11 18:54:40 thehesiod set messages: +
2017-11-15 10:29:56 asvetlov set pull_requests: + <pull%5Frequest4351>
2017-11-14 17:44:27 yselivanov set messages: +
2017-11-14 17:31:09 asvetlov set messages: +
2017-11-14 17:26:28 asvetlov set assignee: yselivanov -> asvetlovmessages: + nosy: + asvetlov
2017-09-25 23:03:02 lukasz.langa set assignee: yselivanov
2017-09-25 23:01:27 lukasz.langa set nosy: + lukasz.langamessages: +
2017-07-04 16:49:25 yselivanov set messages: +
2017-07-01 18:41:21 ned.deily set messages: +
2017-06-19 17:24:50 fafhrd set nosy: + fafhrdmessages: +
2017-06-19 17:21:03 grzgrzgrz3 set nosy: + grzgrzgrz3messages: +
2017-06-18 21:45:35 fafhrd91 set pull_requests: + <pull%5Frequest2319>
2017-06-13 10:12:59 rthr set nosy: + rthr
2017-06-12 10:43:37 yselivanov set messages: +
2017-06-11 14:46:55 yselivanov set messages: +
2017-06-11 14:46:48 yselivanov set messages: +
2017-06-11 14:46:38 yselivanov set messages: +
2017-06-11 14:28:45 yselivanov set messages: +
2017-06-11 14:27:53 yselivanov set pull_requests: + <pull%5Frequest2166>
2017-06-11 14:20:31 yselivanov set pull_requests: + <pull%5Frequest2165>
2017-06-11 14:17:47 yselivanov set pull_requests: + <pull%5Frequest2164>
2017-06-11 07:58:53 yselivanov set messages: +
2017-06-11 07:57:29 yselivanov set messages: +
2017-06-11 07:36:56 yselivanov set messages: +
2017-06-10 21🔞57 fafhrd91 set messages: +
2017-06-10 21:14:30 yselivanov set messages: +
2017-06-10 19:39:26 ned.deily set nosy: + vstinnermessages: +
2017-06-10 19:32:46 ned.deily set messages: +
2017-06-10 19:31:16 ned.deily set priority: normal -> criticalnosy: + ned.deilymessages: +
2017-06-10 14:01:19 yselivanov set messages: +
2017-06-10 14:00:47 yselivanov set messages: +
2017-06-10 04:10:53 yselivanov set pull_requests: + <pull%5Frequest2125>
2017-06-10 04:08:59 yselivanov set pull_requests: + <pull%5Frequest2124>
2017-06-10 04:04:41 yselivanov set messages: +
2017-06-09 22:25:43 yselivanov set messages: +
2017-06-09 22:14:21 Mariatta set nosy: + Mariattamessages: +
2017-06-09 22:04:03 Mariatta set stage: patch reviewversions: + Python 3.7
2017-04-03 17:11:06 misg set pull_requests: + <pull%5Frequest1154>
2017-03-03 23:25:45 fafhrd91 set pull_requests: + <pull%5Frequest371>
2017-03-02 23:48:45 yselivanov set messages: +
2017-02-01 17:22:29 thehesiod set messages: +
2017-02-01 04:35:54 fafhrd91 set versions: + Python 3.6
2017-02-01 04:35:25 fafhrd91 set files: + ssl_shutdown_timeout.patchnosy: + fafhrd91messages: + keywords: + patch
2017-02-01 00:42:25 thehesiod set files: - scratch_1.py
2017-02-01 00:42:01 thehesiod set files: + scratch_1.pymessages: +
2017-02-01 00:39:05 thehesiod create