classification
Title: Asyncio server enters an invalid state after a request with SO_LINGER
Type: behavior Stage: resolved
Components: asyncio Versions: Python 3.8, Python 3.7, Python 3.6
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: Nosy List: asvetlov, drtyrsa, giampaolo.rodola, yselivanov
Priority: normal Keywords: patch

Created on 2018-04-11 17:13 by drtyrsa, last changed 2018-05-21 10:24 by asvetlov. This issue is now closed.

Pull Requests
URL Status Linked Edit
PR 6450 merged drtyrsa, 2018-04-11 17:17
PR 7022 merged miss-islington, 2018-05-21 08:13
PR 7025 merged asvetlov, 2018-05-21 09:06
Messages (4)
msg315196 - (view) Author: Vlad Starostin (drtyrsa) * Date: 2018-04-11 17:13
Long story short, if you have a TCP asyncio-server (implementing asyncio.Protocol) that sends something to socket in connection_made callback, it will leak fds and won't be able to handle some consequent requests, if you will send to it RST right after TCP-handshake.

In my case, these requests are sent by keepalived demon (it makes TCP-checks that way), but they can be easily hand-crafted.


Example server:

import asyncio

class EchoServerClientProtocol(asyncio.Protocol):
    def connection_made(self, transport):
        self.transport = transport
        self.transport.write(b'Say something')

    def data_received(self, data):
        self.transport.write(data)
        self.transport.close()

loop = asyncio.get_event_loop()
coro = loop.create_server(EchoServerClientProtocol, '127.0.0.1', 8888)
server = loop.run_until_complete(coro)
loop.run_forever()


Example client:

import socket
import struct
import time

# first request
sock = socket.socket()
l_onoff = 1
l_linger = 0
sock.setsockopt(socket.SOL_SOCKET, socket.SO_LINGER, struct.pack('ii', l_onoff, l_linger))
sock.connect(('127.0.0.1', 8022))
sock.close()

time.sleep(1)

# second request
sock = socket.socket()
sock.connect(('127.0.0.1', 8888))
print('Got', sock.recv(1024))
sock.sendall(b'Hi there')
print('Got', sock.recv(1024))  # <-- Will hang here
sock.close()


Why is this happening?
1. First request
  1.1. _SelectorSocketTransport.__init__ schedules connection_made and loop.add_reader.
  1.2. connection_made tries to send data to the socket, it fails, _SelectorTransport._fatal_error is called, then _SelectorTransport._force_close is called.
  1.3. _SelectorTransport._force_close removes the reader from the loop (there is none, it's ok), and schedules closing the socket in _SelectorTransport._call_connection_lost.
  1.4. loop.add_reader is called (scheduled on step 1), it calls epoll_ctl, no error is returned because the socket isn't closed yet.
  1.5. the socket is closed by _SelectorTransport._call_connection_lost (scheduled on step 3). The corresponding entry in _SelectorMapping remains and isn't cleaned up.

2. Second request
  2.1. FD from the first request is reused by the OS
  2.2. BaseSelectorEventLoop._add_reader sees that the FD is already in BaseSelectorEventLoop._selector, so it calls _selector.modify
  2.3 _BaseSelectorImpl.modify sees that the events mask is the same, so it uses a shortcut, changing only the callback, but without calling epoll_ctl. The socket won't be polled.

I think the source of the error is in step 1.4, we shouldn't add the reader if we are already closing the transport. I've made a simple PR fixing this, but maybe there are other options here.
msg317217 - (view) Author: Andrew Svetlov (asvetlov) * (Python committer) Date: 2018-05-21 08:13
New changeset a84d0b361a26c05c6fadc6640591ec3feee5bfb5 by Andrew Svetlov (Vlad Starostin) in branch 'master':
bpo-33263: Fix FD leak in _SelectorSocketTransport (GH-6450)
https://github.com/python/cpython/commit/a84d0b361a26c05c6fadc6640591ec3feee5bfb5
msg317220 - (view) Author: Andrew Svetlov (asvetlov) * (Python committer) Date: 2018-05-21 08:35
New changeset b8b800090ff0954117a26ffcb501307823f3d33a by Andrew Svetlov (Miss Islington (bot)) in branch '3.7':
bpo-33263: Fix FD leak in _SelectorSocketTransport (GH-6450) (#7022)
https://github.com/python/cpython/commit/b8b800090ff0954117a26ffcb501307823f3d33a
msg317227 - (view) Author: Andrew Svetlov (asvetlov) * (Python committer) Date: 2018-05-21 10:09
New changeset 7208bfb64b74f31f9704be3f01f26861c9cf092b by Andrew Svetlov in branch '3.6':
[3.6] bpo-33263: Fix FD leak in _SelectorSocketTransport (GH-6450) (#7025)
https://github.com/python/cpython/commit/7208bfb64b74f31f9704be3f01f26861c9cf092b
History
Date User Action Args
2018-05-21 10:24:08asvetlovsetstatus: open -> closed
resolution: fixed
stage: patch review -> resolved
2018-05-21 10:09:54asvetlovsetmessages: + msg317227
2018-05-21 09:06:07asvetlovsetpull_requests: + pull_request6673
2018-05-21 08:35:28asvetlovsetmessages: + msg317220
2018-05-21 08:13:59miss-islingtonsetpull_requests: + pull_request6672
2018-05-21 08:13:57asvetlovsetmessages: + msg317217
2018-04-11 17:17:40drtyrsasetkeywords: + patch
stage: patch review
pull_requests: + pull_request6146
2018-04-11 17:13:48drtyrsacreate