Spring & MyBatis - DataAccessResourceFailureException

기존에 진행하고 있던 프로젝트가 막바지 마무리 단계가 되었습니다. 해당 프로젝트는 백엔드는 Spring, MyBatis, MariaDB로 구성되어 이를 REST API 형태로 제공하고, React 기반으로 프론트엔드가 구축되어 있는 Server-Client 구조의 시스템이었습니다. 

 

하지만 어느 날 저는 다음과 같은 연락을 받게 됩니다 (저를 라이언으로 칭했습니다).

테스터 : 라이언, 지금 웹이 제대로 동작하지 않네요. API가 호출이 제대로 안되는 것 같아요.

라이언 : 네? 지금 서버는 잘 돌아가고 있는데요. 다시한 번 확인해주실 수 있을까요?

테스터 : 어? 아 새로고침 하니까 잘 동작하네요?

라이언 : 아 그런가요? 일단 동작한다고 하시니 테스트 진행해주시고, 원인은 제가 확인해볼게요.

 

꽤 당황스러운 상황이었습니다. 콘솔을 통해 확인해보니 500 에러가 발생하고 있었습니다. 백엔드 시스템에 Logger를 연동해두지 않은 상황이서 정확히 해당 시점에 어떤 이유로 500 에러가 발생한 것인지 원인을 확인할 방법이 없어 조금 막막한 상황이었습니다 (하지만 결과적으로 이 생각에 얽매여서 오류 원인을 볼 수 있는 다른 방법을 생각해보지 않아 문제 해결에 많은 시간을 허비하게 됩니다). 지금까지 프로젝트를 진행하면서 500 에러가 발생한 거의 대부분의 이유는 거의 다음 세가지 중 하나였습니다.

1. API 호출 시 명세와 다르게 잘못 호출함. (가장 흔했던 케이스)
2. 프론트엔드에서 API 명세 상 허용되지 않는 argument를 생성하여 호출하는 예외가 있음.
(ex. 비동기적으로 데이터를 가져와 API 호출하기 전까지 argument가 준비되지 못함)
3. 실수로 DB에서 특정 record를 삭제하여 Data Integrity를 깨뜨림.

하지만 해당 웹은 개발 과정에서 충분히 테스트를 거쳤던 부분이기 때문에 API 자체를 잘못 호출한 일은 없을 것이고, 현실적으로 2번이 문제일 것이라고 추정하고 문제를 접근하려고 하였습니다. 하지만 코드를 열심히 검토해봐도 기존 API 명세에 위배되는 argument를 생성할 예외가 보이지 않았습니다. 더군다나 새로고침 몇 번 해주면 다시 정상적으로 동작한다는 점에서 조금 이상함을 느꼈습니다.

 

그래서 아래와 같이 현재 테스트 하는 환경에 대한 몇 가지 내용들을 정리해보게 됩니다.

1. API 서버를 로컬에서 실행하여 테스트할 경우 해당 이슈가 없음.
2. 현재 백엔드가 배포된 서버는 테스트용 서버여서 개발인원 중에서도 일부만 사용함.
3. 해당 이슈가 거의 오전에 첫 테스트를 진행하면서 발생함.

 

그리고 이 과정에서 다음과 같은 생각을 함께 하게 됩니다.

 

콘솔로 500 에러가 발생하는 당시 호출을 그대로 얻어와서 에러 상황을 재현 할 수 있지 않을까?

 

 

 

이렇게 하면 꼭 Logger를 통한 기록이 아니더라도 해당 에러의 원인에 대한 힌트를 얻을 수 있을 것이라고 생각하였습니다. 더군다나 에러가 발생하는 해당 API는 HTTP Get Method로 호출되었기 때문에 재현도 간단하여 당시 url만 얻으면 바로 재현이 가능했습니다. 그리고 웹 브라우져를 통해서 다음과 같은 에러 내용을 확인할 수 있게 됩니다.

 

 

DataAccessResourceFailureException ?

 

 

 

 

문제 해결에 대한 힌트를 얻을 수 있는 구체적인 Exception 명을 얻게 됩니다. "DataAccessResourceFailureException"이 구체적으로 어떤 Exception인지 알아보기 위해 JavaDoc을 찾아봤습니다.

https://www.javadoc.io/doc/org.springframework/spring/2.0.4/org/springframework/dao/DataAccessResourceFailureException.html

DataAccessResourceFailureException - spring 2.0.4 javadoc

JavaDoc에 명세된 내용을 확인해보면 이 Exception은 "DB와 Connection을 지을 수 없는 경우"와 같이 Spring과 연결된 Data Source와의 연결에 문제가 발생한 경우 주로 발생하게 되는 Exception 이었습니다. 즉, API를 호출하는 과정 자체에는 아무 문제가 없고 DB와의 Connection에 문제가 발생했을 가능성이 높다고 판단하게 되었습니다.

 

이에 따라 저는 한 가지 생각을 더하게 됩니다.

Spring과 DB Connection이 어떤 이유로 끊어지게 되는 건가?

 

 

 

그리고 구글링을 통해서 다음과 같은 정보를 얻게 됩니다.

 

wait_timeout 변수

실제로 MySQL이나 MariaDB에 "SHOW VARIABLES;" Query를 요청하면 "wait_timeout" 이라는 변수를 확인할 수 있습니다. MySQL과 MariaDB는 "DB에 연결된 클라이언트가 아무런 요청없이 특정시간동안 대기할 경우 강제로 Connection을 종료" 하도록 설정되어 있으며, 이때 얼마나 기다릴 것인지에 대한 값을 변수 "wait_timeout" 이라는 변수로 유지하고 있습니다. 이 때 따로 설정하지 않을 경우 기본값으로 28800초 (8시간)으로 설정되어 있습니다.

 

현재 테스트 목적으로 배포한 서버가 저를 포함한 특정 인원들만 사용하고 있었다는 점에서 API 호출은 개발 및 테스트를 진행하는 주간시간 대 외에는 API호출이 일어날 일이 없고, Spring Scheduler에 연동된 API들도 1달에 1번 등과 같이 긴 주기로 동작하는 API들이어서 API 서버에 연결된 MariaDB와의 Connection이 끊어지는 8시간 동안의 공백이 생기기는 충분했습니다.

 

그래서, 어떻게 해결했나요?

autoReconnection=true

Database와 Connection을 설정할 때 autoReconnection 옵션을 true로 설정하여 넘겨주면 됩니다. 해당 옵션을 설정하면, DB와의 Connection이 끊어지더라도 다시 Connection을 형성해줍니다. 그렇기 때문에 이전에 발생하던 DataAccessResourceFailureException을 예방할 수 있습니다.

 

 

잘 해결되었나요?

현재까지는 이렇게 설정값을 바꾸고 재배포한 뒤 해당 이슈로 연락을 받고 있지 않습니다. 하지만 자료들을 찾아본 결과 autoReconnection을 true로 설정하는 것만으로는 근본적인 해결책이 될 수 없다는 의견들도 있습니다. 좀 더 근본적인 해결을 위해서는 validationQuery를 사용해야한다고 하는 데 일단 현재 적용한 솔루션이 잘 동작하고 있으니 추가로 문제 발생 시 다시 고려해보기로 결정하였습니다.

 

 

이번 이슈를 통해 배운 점?

"뭐든 지  쉽게 단정짓지 말라" 라는 것입니다. 저는 해당 이슈를 대하면서 "Logger가 연동되어 있지 않으니 어떤 구체적으로  어떤Exception이 발생한 것인지 알 수 없다." 라고 쉽게 단정지어버리고 문제를 접근하려고 했습니다. 때문에 문제가 발생한 API가 HTTP GET method로 동작하는 API라는 점, console을 통해서 오류가 발생한 API 호출 URL을 얻을 수 있다는 점에서 이를 재현하여 Exception 종류를 얻어볼 수 있다는 점을 생각해보지 않았고, 이 때문에 많은 시간을 낭비하게 되었습니다.

 

"Logger 연동은 필수" Logger 연동 없이도 문제 해결에 대한 힌트를 얻을 수 있는 방법은 있었지만 근본적으로 테스트를 목적으로 배포해둔 서버에 Logger가 연동되어 있지 않다는 점은 상당히 모순적이었습니다. 애초에 Logger를 함께 세팅해두었다면 얼마를 주기로 해당 Exception이 발생하는 지, 종류는 무엇인지 Log를 보고 쉽게 판단할 수 있었을 것 입니다. 이에 따라 Logger의 중요성을 많이 느끼고, 시스템에 Logger를 적용하는 방안을 검토해봐야겠다는 배움을 얻었습니다.