> ## Content Index
> Fetch the complete content index at: https://www.popit.kr/llms.txt
> Use this file to discover other available public pages before exploring further.

# 마이크로 서비스와 TIME_WAIT 문제
- URL: https://www.popit.kr/microservices-and-time-wait-problem/
- Published: 2017-09-14T00:04:51.000Z
- Updated: 2017-09-14T00:49:01.000Z
- Author: 김형준
- Tags: #소프트웨어, TIME_WAIT, Connection Pool, 부하테스트

지난 글에 이어 계속해서 성능 테스트에 대한 이야기 입니다. 전체 성능 테스트에 대해서는 시나리오 작성, 테스트 프로그램, 테스트 수행, 원인 파악 등 실제로 수행한 액션들에 대해서는 별도의 글로 한번 정리하도록 하겠습니다.

[마이크로 서비스](https://www.popit.kr/why-we-had-to-use-microservices-and-docker/)로 구성된 시스템에서는 서비스간 호출이 많이 발생하는데 이들 서비스간 호출하는데 있어 다양한 프로토콜을 사용할 수 있습니다. 제가 운영하는 서비스에서는 HTTP 기반으로 호출하고 데이터는 JSON 형태로 인터페이스를 하고 있습니다. 마이크로 서비스에서 서비스간 호출에 있어 조심해야 할 사항 중에 하나가 Connection Pool을 사용하지 않고 Socket을 지속적으로 만들고 Close 하는 것입니다.

얼핏 생각하면 Connection Pool을 사용하는 것과 사용하지 않는 것의 차이는 네트워크 연결 비용이 조금 더 들어 처리 속도가 조금 느려 진다는 정도만 생각할 수 있습니다. 저도 이번 테스트를 수행하기 전에 이런 생각을 가지고 있었는데 Connection Pool을 사용하지 않으면 서버 자체에 문제를 줄 수 있다는 것을 알게 되었습니다.

## TIME\_WAIT

TCP/IP 연결, 종료 시 연결에 대한 여러 상태가 있는데 TIME\_WAIT은 Close() 요청을 보낸 후 정상적으로 연결을 끊기 전에 지연된 패킷에 대한 문제 해결 등을 위해 일정 시간 동안 연결을 종료하지 않고 대기하고 있는 상태를 말합니다. 이 문서에서는 이 TIME\_WAIT에 대한 자세한 설명은 하지 않겠습니다. 다음 문서에 자세하게 잘 설명되어 있습니다.

- [CLOSE\_WAIT & TIME\_WAIT 최종 분석](http://tech.kakao.com/2016/04/21/closewait-timewait/?ref=popit.kr)

문제는 대기 시간이 짧지 않다는 겁니다. OS 또는 버전에 따라 다르지만 제가 사용하는 우분투 환경에서는 60초 인것 같습니다.

## 모든 네트워크 자원 고갈

클라이언트의 호출을 받은 A 서버가 처리 중에 다른 B 서버의 서비스를 호출할 때 매번 Connection 만들고 Close 하게 되면 TIME\_WAIT 상태가 발생하고 60초 지나면 사라지는 것을 반복하게 됩니다.

이 상테에서 60초 이내에 수만개의 Request가 오면 어떻게 될까요? A 서버의 모든 네트워크 포트가 고갈되어 클라이언트는 더 이상 이 A서버로 요청을 보낼 수 없는 상태가 됩니다. 모든 클라이언트가 요청을 못보내는 것이 아니라 일부 클라이언트의 요청은 받을 수 있고, 일부 클라이언트의 요청은 받을 수 없는 상태가 됩니다.

이런 상태는 평소에는 잘 나타나지 않겠지만 갑자기 사용자가 증가하는 경우 발생할 수 있어 어디가 문제인지 잘 파악하기 어려울 수도 있습니다. 클라이언트가 사용자 브라우저 또는 App 이라고 하면 A 서버의 서비스 로그에는 에러 메시지가 남아 있지 않습니다. 브라우저나 App에서 접속을 못하기 때문입니다.

저도 중국의 대규모 할인 행사인 11/11 행사 준비를 위해 성능 테스트 수행 중에 성능 테스트 프로그램(실제 환경에서는 브라우저 또는 App)에서 서버로 접속할 수 없다는 에러 메시지가 나타났고 이를 근거로 해서 원인을 파악할 수 있었습니다.

서버쪽 네트워크 자원은 다음과 같은 명령으로 모니터링을 수행했습니다.

- watch -n 2 "netstat -an | egrep 'ESTABLISHED|TIME\_WAIT' | wc -l"

이 명령은 2초마다 네트워크 연결 중에 ESTABLISHED와 TIME\_WAIT 상태에 있는 연결 갯수를 보여주는 명령입니다.

![too_many_timewait](https://www.popit.kr/content/images/wp/2017/09/too_many_timewait-600x344.png)

## Golang HTTP 클라이언트 사용 시 주의

이제 문제는 파악했으니 왜 네트워크 연결을 지속적으로 만들고 Close 하는지를 찾아 보았습니다. 가장 먼저 의심한 것은 A 서버에서 B 서버로 API 호출 시 Connection Pool을 사용에 대한 것이었습니다. 하지만 golang에서 기본으로 제공하는 http client는 connection pool이 내장되어 있습니다. 다음과 같이 http package 에 대해 설명과 함께 예제 코드도 있습니다.

![golang_http_package](https://www.popit.kr/content/images/wp/2017/09/golang_http_package-600x176.png)

실제 서비스에서 사용하는 코드를 보니 다음과 같이 Default 옵션을 사용하고 있었습니다.

- client := &http.Client{}  
resp, err := client.Do(req)

특별한 문제는 없어 보이지만 "golang http TIME\_WAIT" 라는 키워드로 검색을 해보면 잘못 사용할 경우 문제가 된다는 것을 알 수 있습니다.

### DefaultMaxIdleConnsPerHost 옵션

다음 문서는 golang을 이용하여 HTTP 요청에 대한 성능 테스트 프로그램을 만들었는데 성능 테스트 프로그램 자체에 TIME\_WAIT 문제가 발생하여 해결한 내용입니다.

- [Tuning the Go HTTP Client Settings for Load Testing](http://tleyden.github.io/blog/2016/11/21/tuning-the-go-http-client-library-for-load-testing/?ref=popit.kr)

내용을 요약하면

- golang의 http client는 connection pool을 사용하고 있으며 여러가지 옵션( Transport)을 이용하여 connection 설정을 할 수 있다.
- Pool 관련 주요 설정 값은 MaxIdleConns, MaxIdleConnsPerHost 값인데 기본 값은 100, 2로 설정되어 있다.
- Pool이 생성되면 요청이 계속해서 들어 오면 MaxIdleConns 옵션에 따라 100개까지 만들지만 MaxIdleConnsPerHost 옵션에 따라 생성된 Connection 중 2개만 남기고 나머지는 모두 Close 하게 된다.

즉 Connection pool의 갯수는 100개 이지만 Host 당 사용 가능한 갯수가 2개이기 때문에 지속적으로 Connection 생성, Close를 반속하면서 TIME\_WAIT이 증가하게 된다는 것입니다.

MaxIdleConnsPerHost 값을 부하 상황에 맞게 적절하게 설정한 후 다시 테스트를 수행하였지만 여전히 TIME\_WAIT이 증가하였습니다.

### Connection 객체는 하나만 생성해야함

golang의 [transport.go](https://golang.org/src/net/http/transport.go?ref=popit.kr#L46) 소스 코드 유심히 살펴보니 다음과 같은 주석이 있었습니다.  

```
// Transports should be reused instead of created as needed.
// Transports are safe for concurrent use by multiple goroutines.
```

즉, Transport는 재사용되니 매번 만들지 말라는 경고 입니다. 그리고 소스 코드를 보니 모든 요청에 대해 http.Client 를 계속 생성하고 있었습니다. 즉 위에서 설정한 MaxIdleConns, MaxIdleConnsPerHost 갯수 만큼 계속 만들어 지고 있었습니다.

다음과 같이 코드를 수정하여 최초 한번만 생성하고 이를 재사용하는 방식으로 개선한 다음 테스트를 수행하니 더 이상 TIME\_WAIT 문제가 발생하지 않았습니다.  

```
var defaultClient *http.Client

func init() {
  defaultTransportPointer, ok := http.DefaultTransport.(*http.Transport)
  if !ok {
    panic(fmt.Sprintf("defaultRoundTripper not an *http.Transport"))
  }
  defaultTransport := *defaultTransportPointer // dereference it to get a copy of the struct that the pointer points to
  defaultTransport.MaxIdleConns = 100
  defaultTransport.MaxIdleConnsPerHost = 100

  defaultClient = &http.Client{Transport: &defaultTransport}
}

// 실제 사용하는 코드에서는 다음과 같이 호출
resp, err := defaultClient.Do(httpReq)
```

## Java Apache HttpClient 사용시 주의

DB 및 서버에 대한 튜닝을 모두 마치고 성능 테스트를 수행하니 성능테스트 Driver에서 다시 동일한 TIME\_WAIT 문제가 발생하였습니다.  

```
java.net.NoRouteToHostException: Cannot assign requested address (Address not available)
  at java.net.PlainSocketImpl.socketConnect(Native Method) ~[na:1.8.0_121]
  at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) ~[na:1.8.0_121]
  at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) ~[na:1.8.0_121]
  at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) ~[na:1.8.0_121]
  at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) ~[na:1.8.0_121]
  at java.net.Socket.connect(Socket.java:589) ~[na:1.8.0_121]
  at org.apache.http.conn.socket.PlainConnectionSocketFactory.connectSocket(PlainConnectionSocketFactory.java:75) ~[httpclient-4.5.3.jar!/:4.5.3]
  at org.apache.http.impl.conn.DefaultHttpClientConnectionOperator.connect(DefaultHttpClientConnectionOperator.java:142) ~[httpclient-4.5.3.jar!/:4.5.3]
  at org.apache.http.impl.conn.PoolingHttpClientConnectionManager.connect(PoolingHttpClientConnectionManager.java:359) ~[httpclient-4.5.3.jar!/:4.5.3]
  at org.apache.http.impl.execchain.MainClientExec.establishRoute(MainClientExec.java:381) ~[httpclient-4.5.3.jar!/:4.5.3]
  at org.apache.http.impl.execchain.MainClientExec.execute(MainClientExec.java:237) ~[httpclient-4.5.3.jar!/:4.5.3]
```

테스트 Driver는 Java로 개발하였는데 이 코드도 Golang의 위에서의 문제를 그대로 가지고 있었습니다.

### Connection Pool 사용

테스트 Driver에서도 API URL 호출을 할때 Connection Pool을 재사용하지 않고 내트워크 연결을 만들고 해제하는 것을 반복하게 되면 짧은 시간내에 너무 많은 TIME\_WAIT 상태가 발생하게 되어 결과적으로는 네트워크 연결을 만들 수 없는 상황이 발생하게 됩니다. 따라서 테스트 Driver로 Connection Pool을 사용해야 합니다. Apache HttpClient의 버전이 여러 종류이고 버전별로 사용방법이 많이 달라서 이것저것 시도를 해보았는데 다음과 같은 코드로 구현하였습니다.  

```
public static void main(String[] args) {
  PoolingHttpClientConnectionManager connManager = new PoolingHttpClientConnectionManager();
  connManager.setMaxTotal(500);
  connManager.setDefaultMaxPerRoute(100);

  // 이 httpClient 객체를 모든 Thread가 같이 사용
  CloseableHttpClient httpClient = HttpClients.custom().setConnectionManager(connManager).build();

  for(...) {
    (new TestThread(httpClient)).start();
  }
}

class TestThread extends Thread {
  public void run() {
  @Override
  public void run() {
    HttpHost targetHost = new HttpHost("server01", 8080);

    while (!stop.get()) {
      CloseableHttpResponse response = null;
      try {
        HttpPost httpPost = new HttpPost("/test");
        response = httpClient.execute(targetHost, httpPost);
        if (!String.valueOf(response.getStatusLine().getStatusCode()).startsWith("2")) {
          HttpEntity entity = response.getEntity();
          String responseString = EntityUtils.toString(entity, "UTF-8");
          LOG.error("Call Error: " + response.getStatusLine().getStatusCode() + " ==> " + responseString);
          this.testStatistics.failed(System.currentTimeMillis() - calledAt);
        } else {
          this.testStatistics.addTestResult(System.currentTimeMillis() - calledAt);
        }
      } finally {
        if (response != null) {
          response.close();
        }
      }
    }
  }
}
```

### Response의 내용을 모두 처리하지 않음

위와 같이 구현하면 정상적으로 CLOSE 된다고 생각했지만 여전히 동일한 문제가 발생하였습니다. 다른 방식으로 구현해도 동일한 문제였습니다. 여러 삽질중에 다음 부분이 문제인 것을 확인하였습니다.  

```
response = httpClient.execute(targetHost, httpGet);
if (!String.valueOf(response.getStatusLine().getStatusCode()).startsWith("2")) {
  HttpEntity entity = response.getEntity();
  String responseString = EntityUtils.toString(entity, "UTF-8");
  LOG.error("API call Error: " + response.getStatusLine().getStatusCode() + " ==> " + responseString);
  this.testStatistics.failed(System.currentTimeMillis() - calledAt);
} else {
  this.testStatistics.addTestResult(System.currentTimeMillis() - calledAt);
}

```

위 코드를 보면 성공시에는 아무런 처리를 하지 않고 실패 시에는 Response의 내용을 출력하도록 되어 있습니다. 몇가지 문서를 확인해보니 response.close() 호출한다고 해서 connection pool에 반환되지 않는 다는 것을 알았습니다.

- [https://stackoverflow.com/questions/4775618/httpclient-4-0-1-how-to-release-connection](https://stackoverflow.com/questions/4775618/httpclient-4-0-1-how-to-release-connection?ref=popit.kr) If you want to re-use the connection then you must consume content stream completely after every use as follows :  
EntityUtils.consume(response.getEntity())

즉 response의 있는 모든 컨텐츠의 내용을 처리해야만 connection을 재사용 가능합니다. Golang에도 이와 비슷한 메소드를 제공하고 있습니다.

- io.Copy(ioutil.Discard, con)

## 결론

이번 테스트 과정을 진행하면서 느낀 것은

- 눈에 보이는 것이 전부가 아니고 시스템은 우리가 생각하는 것과 전혀 다른 상황으로 운영되고 있을 수도 있다.
- 부하 상황에서는 전혀 다른 현상이 발생할 수 있다.
- 하나의 잘못된 코드가 전체 시스템을 망칠 수 있다.
- golang을 사용할 때는 소스 코드의 주석을 잘 살펴보자.
- golang 사용함에 있어 마음 가짐이 Java 초창기 혼돈의 시기와 같은 마음가짐이라야 할 것 같다. 중요 사항들은 하나하나 꼼꼼히 체크해야 할 듯