okhttp3 IOException: unexpected end of stream on Connection

기존 레거시를 msa 서버 어플리케이션으로 이관하는 작업을 중 마주한 에러다.

1. 내용 파악

• 이관된 비즈니스 로직에 오류가 있었다면 들어오는 request 마다 오류가 나야하는데 하루 1~2개 꼴로 간헐적으로 발생한다.
• IOException이라고 해서 헤더 값이나 Payload에 이상한 구분자가 있는지.. 스트림에 영향을 끼쳤을만한 내용을 확인해봐도 아무 문제가 없음.
• 스테이지에서 디버깅을 해봐도 재현이 되질 않음.
• 특정 인스턴스 문제인가 했지만 골고루 찍힌다.

2. 원인

Okhttp3 버그로 보인다.

클라이언트↔ 서버 간 keep-alive timeout 차이로 발생하는 이슈인데 이걸 IOException으로 던지고 있어서 파악하기 어려웠던 것.

- retrofit2로 서버로 request 보내는 클라이언트 duration: 60초

- 서버 nginx 설정 Keep-alive timeout = 20초 

 

오류가 발생하기까지의 순서는 아마 다음과 같을 것이다.

 

에러나는 상황을 재현을 해보려고 timeout 값으로 테스트 중 서버 상태를 netstat으로 확인해보면 FIN_WAIT2 였다.

 

즉, client 입장에서는 더 긴 keep-alive로 ESTABLISHED 상태가 더 오래 지속되기 때문에 server에서는 이미 close() 해버린 connection을 다시 쓰려고 하면서 okhttp3 client단에서 에러가 발생하는 것이다.

 

확인해본 결과는 이렇지만, 그래도 이상한 부분이 있다.
정석적인 TCP 통신에서는 server에서 close하기 전에 FIN, ACK를 보내는 과정이 있어야 되는데 찾아볼 수가 없다.
server가 FIN_WAIT2 상태로 들어갔다면 그걸 client에게 FIN으로 알려주지 않았던걸까?

아니면 알려줬는데도 client에서 무시하는걸까..

여기에 대한 okhttp3 측 대답은 아몰라 처리하기 힘들어 같다...?

 

 

3. 해결

1) RetrofitClient 의 keep-alive timeout을 서버의 타임아웃과 매칭 시켜줬다.

private static final int keepAliveDuration = 60;

2) Connection Failure 발생할 때 다시 tcp connection을 시도하도록 변경했다.

final OkHttpClient.Builder builder = new OkHttpClient.Builder().connectTimeout(connectTimeout, TimeUnit.MILLISECONDS)
        .readTimeout(readTimeout, TimeUnit.MILLISECONDS)
        .writeTimeout(readTimeout, TimeUnit.MILLISECONDS)
        .connectionPool(connectionPool)
        .retryOnConnectionFailure(true);

→ 이후 에러 사라짐

 

결론: Okhttp3(Retrofit) 사용할 때는 keepalive duration값을 요청을 보내는 server의 timeout과 맞추자.

더 생각해볼 것들

1) 나중에 시간나면 서버 상태 다 찍어봐야겠다...
2) retryOnConnectionFailure -> 서버에 부담이 증가 될거 같은데...?

 

4. 참고자료

https://github.com/square/retrofit/issues/1916

Strange behavior: Unexpected end of stream with retrofit 2.1.0 · Issue #1916 · square/retrofit

https://github.com/square/okhttp/issues/2738

OkHttp3 - IOException: unexpected end of stream on okhttp3.Address@9d7c59b5 · Issue #2738 · square/okhttp

https://tech.kakao.com/2016/04/21/closewait-timewait/

CLOSE_WAIT & TIME_WAIT 최종 분석