Websocket 장애에 의한 파일 디스크럽터 제한으로 인한 연결 오류
1. 개요
운영하던 시스템 내에서 채팅 시스템이 안된다는 이슈가 전달되어서 확인해봤는데 채팅 기능이 아예 작동을 하지 않았다. 확인해보니 화면에 다시 진입해도 websocket 연결이 되지 않아서 websocket 서버 로그를 확인해보니 계속해서 아래와 같은 에러 로그가 발생하고 있었다.
Caused by: org.hibernate.exception.JDBCConnectionException: Unable to acquire JDBC Connection
Caused by: java.sql.SQLTransientConnectionException: HikariPool-1 - Connection is not available, request timed out after 30000ms.
Caused by: java.sql.SQLRecoverableException: IO 오류: The Network Adapter could not establish the connection
Caused by: java.io.IOException: 열린 파일이 너무 많음, socket connect lapse 0 ms. /10.10.100.124 1521 30000 1 true
Caused by: java.net.SocketException: 열린 파일이 너무 많음2. 분석
- 첫 번째로 제일 많이 나오는 에러인 ' Caused by: java.net.SocketException: 열린 파일이 너무 많음' 부분을 보면 리눅스에서는 파일을 열면 파일 디스크럽터를 반환하고, 반환된 파일 디스크럽터는 파일을 읽고 쓰는데 사용한다고 한다.
- 여기서 파일 디스크럽터는 리눅스 환경의 java 소켓 통신(http, api, jdbc connection) 또한 파일로 취급된다고 하는데 java 소켓 통신이 너무 많아져 파일이 시스템 제한을 초과하여 발생하는 문제로 보인다.
- 따라서 서비스 화면 진입 후 웹소켓 연결을 하는데 웹소켓 연결하는 것 또한 파일 취급이 되어 파일이 추가가 되어야 하는데 이미 시스템 제한에 막혀 웹소켓 관련 파일 디스크럽터가 추가되지 않아 채팅 장애가 발생한 것으로 보인다.
실제로 서비스 화면에 들어가 웹소켓 연결을 해보면 /proc/'pid'/fd 경로에 파일 디스크럽터가 추가되는 것을 볼 수 있었다.
그렇다면 무슨 원인으로 파일 디스크럽터가 시스템 제한에 다다를 정도로 증가했던 것일까 찾기 시작했다.
3. 해결
-
일단 서비스가 동작하게끔 하는게 급했기 때문에 웹소켓 서버를 재기동 했다. 재기동하니 파일 디스크럽터도 시스템 제한 내였고 웹소켓도 정상 작동하여 서비스에 장애가 나지 않고 정상적으로 기능했다.
-
재기동 이후에도 확인해보니 파일 디스크럽터 수가 3400개 정도로 비정상적으로 늘어나는 것을 확인했다. 그래서 해당 파일이 생겼던 시점에 대한 로그를 확인하는데 아래와 같은 에러가 지속적으로 발생했었다.
org.springframework.web.util.NestedServletException: Request processing failed; nested exception is org.springframework.web.socket.sockjs.SockJsException: Uncaught failure in SockJS request, uri=http://domain/secured/ws-stomp/270/1h22lmj5/eventsource?userId=??; nested exception is org.springframework.web.socket.sockjs.SockJsTransportFailureException: Failed to open session; nested exception is java.lang.IllegalArgumentException: Async support must be enabled on a servlet and for all filters involved in async request processing. This is done in Java code using the Servlet API or by adding "<async-supported>true</async-supported>" to servlet and filter declarations in web.xml. Also you must use a Servlet 3.0+ container-
이전에도 위와 같은 에러가 났던 적이 있었는데 그땐 내장 was로 undertow로 사용하게끔 설정을 했는데 build.gradle에서 tomcat module을 exclude하는 부분에서 문법적으로 오류가 있어 tomcat으로 실행이 됐었다. 그래서 tomcat, undertow 충돌로 인해 해당 부분을 정상적으로 수정하니 해결이 됐었다. 그래서 해당 소스도 tomcat module exclude 부분을 정상적으로 수정하는 조치를 취했다.
-
그래도 전의 경우엔 서버 자체를 기동시킬 때 나타나는 문제였는데 지금 같은 경우는 정상적으로 작동하다 갑자기 웹소켓 연결 부분에서 나타나는 에러였기에 조금 더 찾아봤다. 에러 로그에서 아래 부분을 중점적으로 찾아본 결과 비동기 요청에 대해서 로그 그대로 비동기 처리에 대한 설정이 필요하다고 한다.
This is done in Java code using the Servlet API or by adding "<async-supported>true</async-supported>" to servlet and filter declarations in web.xml. Also you must use a Servlet 3.0+ container- 그래서 WebMvcConfigurer 부분에서 아래와 같이 비동기 처리에 대한 설정을 추가해주었다.
@Override
public void configureAsyncSupport(AsyncSupportConfigurer configurer) {
configurer.setDefaultTimeout(5000);
configurer.setTaskExecutor(mvcTaskExecutor());
}
@Bean
public AsyncTaskExecutor mvcTaskExecutor() {
ThreadPoolTaskExecutor taskExecutor = new ThreadPoolTaskExecutor();
taskExecutor.setThreadGroupName("mvc-executor");
return taskExecutor;
}- 위 설정 추가 이후에도 동일한 증상이 나타나 이번엔 nginx access log를 봤는데 웹소켓 connect 요청이 계속해서 발생했다. 그래서 웹소켓 연결 부분에서 문제가 있는 것 같아 시스템 로그 및 디버그를 하며 확인을 해보니 웹소켓 연결 시 jwt를 헤더에 포함해 connect 시도 하는데 jwt의 유효기간이 만료된 경우 connect 에러가 발생해 비정상적으로 웹소켓 연결 시도를 보내는 것이 확인되었다. 그래서 웹소켓 연결 시 jwt를 새로 발급 받아 연결 요청을 보내도록 처리했다.
4. 마무리
- 위 처리 이후 비정상적인 웹소켓 연결 요청이 사라졌고 파일 디스크럽터도 모니터링한 결과 정상 범위 내에 있었다. 위 장애를 해결하면서 파일 디스크럽터에 대해 알게 되었고 개발하면서 이와 같은 상황도 고려해야 한다는 것을 알게 되었다. 그리고 jwt를 사용할 땐 항상 유효기간을 유념하자 !
