내가 겪은 이야기

실무에서 Requests 라이브러리는 꽤 자주 사용하는 편인데 얼마전 겪었던 다소 황당했던(?) 일을 얘기해보려 한다.

Production 환경에서는 네트워크 통신 시 항상 Timeout 관리를 해줘야 한다. 인터넷이라는 공간은 꽤나 불안정한 곳이기에 Client가 보낸 요청을 Server에서 못받을 수도 있고 반대로 Server에서 응답한 내용을 Client가 못 받는 경우도 있다. 때문에 항상 네트워크 통신 로직이 포함될 때는 너무 오랫동안 응답을 기다리다가 의도치 않게 전체 로직에 영향이 가지 않도록 적절한 Timeout 설정은 필수라 할 수 있다.

Requests 라이브러리에서도 Timeout 설정을 지원하고 있는데 관련 내용을 살펴보면 아래와 같다.

https://docs.python-requests.org/en/master/user/advanced/#timeouts

Most requests to external servers should have a timeout attached, in case the server is not responding in a timely manner. By default, requests do not time out unless a timeout value is set explicitly. Without a timeout, your code may hang for minutes or more.

Timeout을 직접 설정 하지 않으면 time out이 발생하지 않는다고 한다. 이런 중요한 내용을 눈에 잘 띄게 해놓으면 더 좋았을 것이라는 아쉬움이 좀 남지만… 아무튼. 좀 더 내용을 살펴보면

The connect timeout is the number of seconds Requests will wait for your client to establish a connection to a remote machine (corresponding to the connect()) call on the socket. Once your client has connected to the server and sent the HTTP request, the read timeout is the number of seconds the client will wait for the server to send a response. (Specifically, it’s the number of seconds that the client will wait between bytes sent from the server. In 99.9% of cases, this is the time before the server sends the first byte).

connect timeout 과 read timeout 을 설정할 수 있다고 한다. 설정 방법은 아래와 같다.

# connect timeout 과 read timeout 둘 다 5초로 설정된다.
r = requests.get('https://github.com', timeout=5)

# connect timeout 3.05초, read timeout 27로 각각 설정도 가능하다.
r = requests.get('https://github.com', timeout=(3.05, 27))

connect timeout은 3초, read timeout은 50초 설정한 뒤 파일을 업로드하는 코드를 실행했는데 결과는…?(업로드 시 3초 이상 소요되는 파일 크기)

# client.py
import sys
import requests

url = 'http://10.120.1.111/'

file = open(sys.argv[1], 'rb')
resp = requests.post(url, files={'file': file}, timeout=(1, 50))
print(resp)

~$ python3 client.py 100MB_file

Traceback (most recent call last):
...생략
  File "/Users/hsyang/.pyenv/versions/3.6.7/lib/python3.6/http/client.py", line 1065, in _send_output
    self.send(chunk)
  File "/Users/hsyang/.pyenv/versions/3.6.7/lib/python3.6/http/client.py", line 986, in send
    self.sock.sendall(data)
socket.timeout: timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
...생략
  File "/Users/hsyang/.pyenv/versions/3.6.7/lib/python3.6/http/client.py", line 1065, in _send_output
    self.send(chunk)
  File "/Users/hsyang/.pyenv/versions/3.6.7/lib/python3.6/http/client.py", line 986, in send
    self.sock.sendall(data)
urllib3.exceptions.ProtocolError: ('Connection aborted.', timeout('timed out',))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "client.py", line 6, in <module>
    resp = requests.post(url, files={'file': file}, timeout=(3, 50))
...생략
  File "/Users/hsyang/.pyenv/versions/test/lib/python3.6/site-packages/requests/adapters.py", line 498, in send
    raise ConnectionError(err, request=request)
requests.exceptions.ConnectionError: ('Connection aborted.', timeout('timed out',))

Connection aborted !?!?

연결이 강제로 끊긴다. 아니 이게 무슨 상황이지…? Connection timeout에 대한 정의를 내가 잘못 알고 있는건가?

Connection Timeout

Requests 라이브러리는 HTTP 요청(Client)을 위해 사용한다. HTTP는 TCP 기반에서 구현되는데 TCP는 그 특성상 Connection을 먼저 맺은 후 데이터를 주고받는다. Connection을 맺는 과정은, 아마 한번 쯤은 들어봤을 Three-way-handshaking 과정을 거친다.

보통 Connection Timeout 이라 함은 위 과정이 설정한 시간 안에 이뤄지지 않을 때 발생하는 것이라고 할 수 있다.

Connection Timeout 재현 테스트

우선 위 과정을 실제 눈으로 확인해보기 위해 간단한 Python http 서버 코드와 telnet, tcpdump 명령어를 활용해보자.

tcpdump 명령어 활용법은 이 글을 참고하자.

먼저 원격 Server 1대에 Python3 설치를 한 후 아래 코드를 작성하자.

• server.py

  # server.py
  from http.server import HTTPServer, BaseHTTPRequestHandler
  from http import HTTPStatus
  
  class MyHandler(BaseHTTPRequestHandler):
  
      def do_POST(self):
          content_length = int(self.headers['Content-Length'])
          read = 0
          buf = bytearray()
          while read < content_length:
              data = self.rfile.read(min(65536, content_length - read))
              read_bytes = len(data)
              print(f"read {read_bytes} bytes")
              read += read_bytes
              buf += bytearray(data)
  
          print(f"read complete. {len(buf)} bytes are read")
  
          self.send_response_only(HTTPStatus.CREATED)
          self.end_headers()
  
  
  if __name__ == '__main__':
      server = HTTPServer(('0.0.0.0', 80), MyHandler)
      try:
          server.serve_forever()
      except Exception as e:
          print(e)
      server.server_close()
  

그리고 실행하자.

# Server
~$ sudo python3 server.py

그 뒤 Server 터미널을 하나 더 연결해서 tcpdump를 실행하여 네트워크 패킷을 캡쳐하자.

# Server
~$ sudo tcpdump -i ens192 -nn port 80

그리고 로컬 PC에서 telnet 명령어를 이용하여 연결을 해보자.

# telnet <Server IP> <Server Port>
~$ telnet 10.120.1.111 80

그러면 서버에서 실행해두었던 tcpdump 터미널에서 아래와 같이 Three-way-handshaking 패킷 3개를 확인할 수 있다.

22:16:44.342994 IP 10.120.1.254.56869 > 10.120.1.111.80: Flags [S], seq 3554504166, win 65535, options [mss 1314,nop,wscale 6,nop,nop,TS val 394584072 ecr 0,sackOK,eol], length 0
22:16:44.343055 IP 10.120.1.111.80 > 10.120.1.254.56869: Flags [S.], seq 2399293706, ack 3554504167, win 28960, options [mss 1460,sackOK,TS val 1076530274 ecr 394584072,nop,wscale 7], length 0
22:16:44.347394 IP 10.120.1.254.56869 > 10.120.1.111.80: Flags [.], ack 1, win 2054, options [nop,nop,TS val 394584077 ecr 1076530274], length 0

위 패킷 내용을 설명하자면 아래와 같다.

10.120.1.254 : 로컬 IP
10.120.1.111 : 원격 Server IP

Flags [S]  : SYN 패킷
Flags [S.] : SYN+ACK 패킷
Flags [.]  : ACK 패킷

자, 여기서 Connection Timeout을 발생시켜보기 위해 SYN+ACK 패킷이 전송되지 않도록 해보자.

방금 전 사용한 telnet client에는 Connection Timeout 설정이 없으므로 Timeout 설정이 가능한 Python Client 코드를 간단하게 작성해보자.

• client.py

  # client.py
  import sys
  import requests
  
  # server ip : 10.120.1.111
  url = 'http://10.120.1.111/'
  
  # connection timeout 3 seconds
  # read timeout 50 seconds
  resp = requests.get(url, timeout=(3, 50))
  print(resp)
  

Server 터미널을 하나 더 연결해서 iptables 명령어로 packet 전송을 막아보자.

# Server 에서 외부로 나가는 tcp 패킷 중 아래 정보와 일치하는 패킷은 drop 한다.
#   - destination IP = 10.120.1.254 
#   - source port number = 80
~$ sudo iptables -A OUTPUT -p tcp -d 10.120.1.254 --sport 80 -j DROP

그리고 로컬에서 client.py 를 실행해 보면 3초 뒤 아래와 같은 예외가 발생한다.

~$ python3 client.py

생략...
  File "/Users/hsyang/.pyenv/versions/test/lib/python3.6/site-packages/urllib3/util/connection.py", line 70, in create_connection
    sock.connect(sa)
socket.timeout: timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
...생략
  File "/Users/hsyang/.pyenv/versions/test/lib/python3.6/site-packages/urllib3/connection.py", line 164, in _new_conn
    (self.host, self.timeout))
urllib3.exceptions.ConnectTimeoutError: (<urllib3.connection.HTTPConnection object at 0x10b3c4940>, 'Connection to 10.120.1.111 timed out. (connect timeout=3)')

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
...생략
  File "/Users/hsyang/.pyenv/versions/test/lib/python3.6/site-packages/urllib3/util/retry.py", line 398, in increment
    raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPConnectionPool(host='10.120.1.111', port=80): Max retries exceeded with url: / (Caused by ConnectTimeoutError(<urllib3.connection.HTTPConnection object at 0x10b3c4940>, 'Connection to 10.120.1.111 timed out. (connect timeout=3)'))

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "get-client.py", line 6, in <module>
    resp = requests.get(url, timeout=(3, 50))
...생략
  File "/Users/hsyang/.pyenv/versions/test/lib/python3.6/site-packages/requests/adapters.py", line 504, in send
    raise ConnectTimeout(e, request=request)
requests.exceptions.ConnectTimeout: HTTPConnectionPool(host='10.120.1.111', port=80): Max retries exceeded with url: / (Caused by ConnectTimeoutError(<urllib3.connection.HTTPConnection object at 0x10b3c4940>, 'Connection to 10.120.1.111 timed out. (connect timeout=3)'))

이 때 Server의 tcpdump 캡쳐 내용에는 SYN 패킷만 출력됨을 확인할 수 있다. 즉, SYN+ACK 패킷을 밖으로 내보내지 않았음을 확인할 수 있다.

22:49:55.624835 IP 10.120.1.254.57298 > 10.120.1.111.80: Flags [S], seq 3098430240, win 65535, options [mss 1314,nop,wscale 6,nop,nop,TS val 1742337210 ecr 0,sackOK,eol], length 0

Connection Timeout 재현 성공 !

파일 업로드 중 발생했던 예외와 Connection Timeout 재현 테스트 시 발생한 예외 비교

client.py 에서 발생한 예외 내용을 보면 글 초반부에 보았던 내용과는 약간 다름을 알 수 있다.

• 업로드 중 예외 발생 시

  File "/Users/hsyang/.pyenv/versions/test/lib/python3.6/site-packages/requests/adapters.py", line 498, in send
      raise ConnectionError(err, request=request)
  requests.exceptions.ConnectionError: ('Connection aborted.', timeout('timed out',))
  

• Connection 생성에 실패할 때 (client.py)

  File "/Users/hsyang/.pyenv/versions/test/lib/python3.6/site-packages/requests/adapters.py", line 504, in send
      raise ConnectTimeout(e, request=request)
  requests.exceptions.ConnectTimeout: HTTPConnectionPool(host='10.120.1.111', port=80): Max retries exceeded with url: / (Caused by ConnectTimeoutError(<urllib3.connection.HTTPConnection object at 0x10b3c4940>, 'Connection to 10.120.1.111 timed out. (connect timeout=3)'))
  

언뜻 보면 같아보이지만 에러 내용 자체는 구분되어 있음을 알 수 있다. (필자도 이 포스팅을 작성하면서 알았다… 무슨 숨은 그림 찾기도 아니고 이름을 너무 비슷하게 해놔서 언뜻보면 같은 에러로 보인다 ㅠ)

• requests.exceptions.ConnectionError
• requests.exceptions.ConnectTimeout

이 말인 즉슨, 이 두 개를 구분할 수 있다는 얘기인데… Timeout 설정을 구분해서 할 수는 없을까? 싶어서 열심히 구글링해 본 결과, 필자와 동일한 황당함(?)을 겪은 한 유저가 requests 라이브러리 github 저장소 issue 등록을 해놨더라. connection timeout 과 send timeout을 구분하고 싶다는 얘기였는데 아쉽게도 requests 라이브러의 Maintainer가 그럴 계획 없음! 이라고 못을 박았놨다…

https://github.com/psf/requests/issues/3099#issuecomment-216991348

So the timeout logic used in requests is fundamentally that of urllib3, so it should be sufficient
to make the change there: feel free to open a feature request and we can help you through the
change. And in the shorter term, feel free to investigate using setdefaulttimeout.

요약하자면,

requets 라이브러리는 Python built-in 라이브러리인 urllib3를 이용하기 때문에 send timeout 구현이 필요하다면 해당 라이브러리에서 구현하는게 좋은 것 같다! 혹은 setdefaulttimeout으로 문제 해결에 활용할 수 있는지 알아봐라!

란다. 위 대답을 들은 해당 유저가 urllib3 라이브러리 github 저장소에도 issue를 등록해 두었는데(무려 2016년…!!) 아직도 open 상태다.

https://github.com/urllib3/urllib3/issues/857

결론

자신의 코드에 파일 업로드 로직이 없다면 connection timeout을 사용하면 되지만 필자와 같이 파일 업로드 로직이 있는 경우 connection timeout 이 실제로 (connection timeout + send timeout) 임을 감안하여 connection timeout 값을 충분히 크게 설정하는 방법밖에 없는 것 같다. T.T

https://github.com/psf/requests/issues/3099#issuecomment-216991348

위 github issue 코멘트를 보면, 아래 3가지 방법이 있는것 같은데 어느것 하나 쉬워 보이진 않는다.

1. python3의 경우 C로 구현된 io.BufferedReader 클래스를 수정하거나
2. standard library의 buffering 옵션을 끄고 buffering 관련 코드를 다시 작성하거나 (성능에 매우 안좋다.)
3. setdefaulttimeout 활용 방법에 대해 조사하고 테스트 해본다.

1,2 사실 좋은 방법이 아닌 것 같고(능력도 안되고;;;) 3번을 진행해보고 포스팅을 업데이트해야겠다. 혹시 먼저 필자와 같은 삽질을 해본 분이 있으면… 좀 알려주십쇼.(꾸벅) 허헛.