New submission from kyuupichan:

An asyncio SSL server frequently sees duplicated connection_made() calls for an 
incoming SSL connection.  It does not happen to all SSL connections; perhaps 
10-25% of them.  It never happens to TCP connections. 

Here are some examples of logs from one I run.  I see this on MacOSX and 
DragonflyBSD, others have reported the same on Linux, so I believe it's a quirk 
in asyncio and not O/S specific.  I assume it is a bug in the wrapping of the 
raw TCP transport with an SSL one.

2017-04-20 07:22:44.676180500 INFO:ElectrumX:[14755] SSL 218.185.137.81:52844, 
256 total
2017-04-20 07:22:45.666747500 INFO:ElectrumX:[14756] SSL 218.185.137.81:52847, 
256 total

The log is output on a connection_made() callback to a protocol, and not from 
the protocol's constructor.  They are very close together, from the same IP 
address and ports that are close together.  The first connection was closed 
with connection_lost() before the 2nd connection_made() because the total 
session count (here 256) did not increase.

Here is another section of my log with 2 more examples.  Totals are not 
monotonic because of course disconnections (not logged) happen all the time.

2017-04-20 07:30:31.529671500 INFO:ElectrumX:[14796] SSL 193.90.12.86:42262, 
259 total
2017-04-20 07:31:04.434559500 INFO:ElectrumX:[14797] SSL 70.199.157.209:10851, 
259 total
2017-04-20 07:31:05.765178500 INFO:ElectrumX:[14798] SSL 70.199.157.209:10877, 
259 total
2017-04-20 07:31:32.305260500 INFO:ElectrumX:[14799] SSL 64.113.32.29:35025, 
256 total
2017-04-20 07:31:44.731859500 INFO:ElectrumX:[14800] SSL 188.107.123.236:60867, 
255 total
2017-04-20 07:31:45.504245500 INFO:ElectrumX:[14801] SSL 188.107.123.236:60868, 
255 total
2017-04-20 07:31:48.943430500 INFO:ElectrumX:[14802] SSL 136.24.49.122:54987, 
255 total
2017-04-20 07:31:59.967676500 INFO:ElectrumX:[14803] TCP 113.161.81.136:2559, 
256 total
2017-04-20 07:32:03.249780500 INFO:ElectrumX:[14804] SSL 69.121.8.201:63409, 
256 total

Another reason I believe this is an asyncio issue on the server side is that 
someone else's server software that doesn't use asyncio logs in a similar way 
and does not see duplicated incoming "connections".

----------
components: asyncio
messages: 291919
nosy: kyuupichan, yselivanov
priority: normal
severity: normal
status: open
title: Duplicated connection_made() call for some SSL connections
type: behavior
versions: Python 3.5, Python 3.6

_______________________________________
Python tracker <rep...@bugs.python.org>
<http://bugs.python.org/issue30105>
_______________________________________
_______________________________________________
Python-bugs-list mailing list
Unsubscribe: 
https://mail.python.org/mailman/options/python-bugs-list/archive%40mail-archive.com

Reply via email to