[개발일지] MongoSocketException 이슈 해결기

갑자기 내가 작업했던 rpc에서 이유없는 INTERNAL 에러가 내려왔다.
 
데이터독을 보니

• MongoSocketWriteException
• MongoSocketReadException: Prematurely reached end of stream (after a period of inactivity)

 
요 에러들이 지속적으로 발생하고 있었다.
Elasticsearch가 복병일 줄 알았더니,, 그 전에 데이터를 조회하기 위해 Mongo에 접근할 때 에러가 났다.
 
아무런 변화가 없었는데 갑자기 왜 이런 에러가 났을까?
 

원인 파악
추측1: 커넥션풀 이슈?
추측2: 유휴 커넥션 이슈?
해결

 

원인 파악

정말 변화가 없었을까.. 파악해보았다.
생각해본 변화는

• 기능 개선
• 코드 리팩토링

 
이뿐이었다..
 
그런데 확인해보니
 

이전부터 50% 에러율로 에러가 나고 있었다.ㅎㅎ;;
트래픽이 적다보니 따로 이상 알림이 오는 경우가 없어서 잘 알아채지 못했던 것이다.
 
그렇다면,, 어떤 부분을 고쳐야 이 에러가 해결될까?
일단 이 rpc의 특이점을 생각해보았다. 이 rpc는 다른 요쳥들과 다르게, 지속적으로 호출되는 rpc가 아니다.
그래서 오랫동안 요청이 오지 않아, 커넥션 맺을 때 timeout이 나는 등의 에러가 날 수 있겠다라고 대강 추측해보았다.
 
일단, 트래픽이 얼마나 되는지 확인을 해보았다.
 

 
초당 0.1 req 미만이다. 즉 1분에 6개 요청도 안된다는 뜻!
 
그리고 커넥션풀 설정도 확인해보았다.

[end_point]/[database_name]?ssl=false&authSource=admin&retryWrites=true&w=majority&minPoolSize=40&maxPoolSize=40&readPreference=primaryPreferred

커넥션풀 사이즈를 40으로 지정했다.
 
 
요 내용들을 기반으로 알아내보자.
 

추측1: 커넥션풀 이슈?

일단 1번째로 커넥션풀 문제인가?라는 생각을 했다.
커넥션을 맺으려고 했는데 커넥션 풀에 사용중인 커넥션이 full이어서? 였다. 하지만 위에서 보면 요청수가 현저히 적기 때문에 이 이유는 아닐거라고 생각했다.
 
그리고 실패 응답이 오는 시간을 보면 63ms이다.

커넥션 요청 기다리는 시간이 기본 2분이다. 63ms 로 실패하고 있으니 더더욱 아니라고 판단했다.

maxWaitTime() Sets the maximum time to wait for an available connection.
Default: 2 minutes

 

추측2: 유휴 커넥션 이슈?

서치하다가 알아보게 된! 2번째 추측은 유휴 커넥션이 오랫동안 유지될 때 (재사용이 되지 않을 때) inactivity 상태가 되어서 해당 커넥션을 사용하려는 클라이언트에게 에러를 뱉는 것이다.
 
유휴 커넥션은 커넥션풀에서 제거되지 않고, 재사용이 가능한 커넥션이다. 이는 커넥션을 재사용하여 매번 새로운 커넥션을 생성하는 오버헤드를 줄일 수 있어 효율적이다. (커넥션 생성은 메모리와 네트워크 리소스를 소비한다. 이를 피할 수 있으니 굳)
하지만, 유휴 커넥션이 오랫동안 유지되면, 일부 네트워크 장비나 환경에서 해당 연결을 끊을 수 있다. 이로 인해 클라이언트가 해당 커넥션을 사용하려고 할 때 "Socket read exception"과 같은 에러가 발생할 수 있다.
 
다음은 Microsoft Azure MongoDB 관련 공식문서 중 일부 내용이다.

에러:
MongoDB 클라이언트 네트워킹 문제(예: 소켓 또는 endOfStream 예외)

설명:
네트워크 요청이 실패한 문제이다. 
이는 MongoDB 클라이언트가 사용하려는 비활성 TCP 연결로 인해 발생하는 경우가 많다. 
MongoDB 드라이버는 종종 연결 풀링을 사용하므로 요청에 사용되는 풀에서 임의의 연결이 선택된다. 
비활성 연결로 인해 일반적으로 Azure Cosmos DB 끝에서 4분 후에 시간 초과된다.

해결 방법:
애플리케이션 코드에서 이러한 실패 요청을 다시 시도하거나, 
MongoDB 클라이언트(드라이버) 설정을 변경하여 4분 제한 시간 전에 비활성 TCP 연결을 해제하거나, 
TCP 연결을 활성 상태로 유지하도록 OS keepalive 설정을 구성할 수 있다. 
연결 메시지를 방지하기 위해 maxConnectionIdleTime을 1-2분으로 설정하도록 연결 문자열을 변경하려고 한다.
- Mongo 드라이버: maxIdleTimeMS=120000 구성
- Node.JS: socketTimeoutMS=120000 구성, autoReconnect = true, keepAlive = true, keepAliveInitialDelay = 3분

 
여기에서 maxConnectionIdleTime 설정에 대한 힌트를 얻었다.
MongoDB 공식 문서에서 이에 대한 설명을 볼 수 있다.

maxConnectionIdleTime() 
Sets the maximum time a connection can be idle before it's closed.
연결이 닫히기 전에 유휴 상태로 있을 수 있는 최대 시간을 설정한다.

기본적으로 MongoDB Java 드라이버의 maxConnectionIdleTime 값은 0으로 설정되어 있다. 즉, 커넥션의 유휴 시간 제한이 없어서 커넥션풀에서 유휴 커넥션을 제거하지 않는다.
 
그리고 회사에서 MongoDB 설정에 대한 가이드도 참고했다.

maxConnectionIdleTime

특정 시간동안 아무런 사용이 없으면 해당 컨넥션은 Invalid한 상태로 마킹되어서 재사용되지 못하도록 한다. 
이 시간이 짧으면 짧을수록 Connection close/open 작업이 빈번하게 발생하게 된다. 
가능하다면 최대한 길게 설정(처음 시작하는 서비스라면, 
10분 정도로 설정하고 향후 서비스 상황을 봐가면서 최적값으로 튜닝하는 방법을 권장)하도록 하자.

 
"특정 시간동안 아무런 사용이 없으면 해당 커넥션은 Invalid한 상태로 마킹되어서 재사용되지 못하도록 한다."
여기서 내가 추측한 두번째 가설이 맞았다는 걸 확인할 수 있었다.
 
초당 0.1 req 도 되지않아서 커넥션이 재사용되지 않은 채 invalid되어서 해당 커넥션을 접근할 때 socketException이 난 것이다.
 
즉, 추측2가 맞았다!

해결

그래서 다음과 같이 maxConnectionIdleTime 설정을 추가해서 배포해보았다.
10분으로 설정하여서, 유휴 커넥션이 10분동안 사용되지않으면 커넥션풀에서 제거된다.
즉, 해당 커넥션을 클라이언트에서 접근할 수 없게 된다.

MongoClients.create(
  MongoClientSettings.builder()
      .applyToConnectionPoolSettings { builder: ConnectionPoolSettings.Builder ->
          builder.maxConnectionIdleTime(10, TimeUnit.MINUTES) // 커넥션 풀 최대 유휴 시간: 10분
      }
      .applyConnectionString(ConnectionString(targeterMongoProperties.uri))
      .build()
)

짜잔 다음과 같이 배포 이후(18:00 이후)에 에러가 0인 것을 볼 수 있다.! 꺄르륵 해결했어!!

그리고 리더의 든든한 리뷰까지 받았다 호호!!

 
실제 운영을 해야지 겪을 수 있는 값진 경험이었다. 오랜만에 깊게 파면서 알아낸 듯! (너무 궁금해서 잠들기 전까지도 생각나는 거 계속 노션에 적어두고, GPT한테 계속 질문했다.ㅋㅋ) 해결까지 해서 너무너무 뿌듯뿌듯~!!~!!
 
 

참고 링크

Specify MongoClient Settings — Java Sync

Azure Cosmos DB의 API for MongoDB에서 일반적으로 발생하는 문제 해결

주니어 개발자의 오픈소스 활동 이야기 | 카카오페이 기술 블로그