[Pet-Hub] Lock을 걸지 않아도 발생한 PessimisticLockException해결

✍ 문제 상황

잘 되고 있던 분양글 조회 API가 제대로 응답하지 않는 문제가 발생해서 로그를 살펴보니, 두가지 키워드로 문제 상황을 파악할 수 있었습니다.

PessimisticLockException과 TransactionTimeOut 입니다.
락을 획득하지 못해서 예외가 발생했고, 트랜잭션이 시간내에 처리되지 못하는 현상이 발생했습니다.
잘 되던 API가 갑자기 작동하지 않을때는, 코드 레벨의 문제보다 인프라나 DB와 같은 다른 곳에 문제가 있을거라고 생각하고 문제 해결법을 찾아나섰습니다.

😀 원인 분석과 문제 해결

문제가 발생한 API의 코드를 보겠습니다.

분양글을 상세 조회하는 API 입니다.
분양글 번호에 맞는 분양글을 조회하고, 조회수를 올려주는 비즈니스 로직을 호출하는 간단한 형태로 작성되어 있습니다.

그 당시 문제 상황을 보면, 분양글을 조회하고 게시글 카운트를 업데이트 해주는 부분까지 쿼리가 정상적으로 DB에 나가는 것은 로그로 확인이 되었습니다.

하지만 POSTMAN은 무한 루프에 빠지게 되었고, 조회 결과도 나오지 않다가 500번 에러를 응답하기에 로그를 확인해보니 PessimisticLockException과 TransactionTimeOut이라는 힌트를 얻을 수 있었습니다.

DB의 문제점 확인

DB 서버에 접속해서, 실행중인 쿼리를 확인해보니 읽기를 담당하는 Slave DB에는 모든 쿼리가 정상 수행 후 종료되었지만 Master DB의 쿼리는 계속 실행중이면서 종료되지 않는 무한 루프에 빠진 쿼리를 발견하였습니다.

조회수 증가 로직을 제거 후 테스트

그렇다면 쓰기 작업에서 문제가 발생한다고 판단하여, 조회수를 증가시키는 비즈니스 로직을 주석처리 후 다시 API 조회를 시도해보았습니다.

그 결과 정상 조회되는 것을 확인하였고, 조회수 증가 로직에서 문제가 발생했다는 것을 파악했습니다.

진짜 원인은 뭘까?

Transaction의 충돌 문제도 아니고, Lock을 걸어 놓은 Service 로직이 아님에도 락을 획득하지 못하고 Transaction이 시간내에 수행되지 못하는 에러가 발생하고 있어서 Grafana 대시보드를 확인하러 들어갔습니다.

잘 되고 있던 Grafana도 No Instance라는 메시지를 표시하며 아무런 상태를 표시하지 않았습니다. 그렇다면 서버가 다운된것도 아니였기에 의아했습니다.

서버에 접속해서 Prometheus와 Grafana의 로그를 확인하던.. 그때..!

Prometheus 로그에서 특이점을 발견하게 되었습니다.

EC2 인스턴스의 저장공간이 부족하다는 내용의 로그가 계속 출력되고 있었던 것입니다.
RDS를 사용하지 않고 EC2 인스턴스 내에 MySQL을 띄워두었기 때문에, 데이터를 쓰는 작업에서 인스턴스의 용량이 필요할 것이고 용량이 부족해서 요청을 처리하지 못하면 작업이 무한 대기 될 수 있다는 가능성을 생각하게 되었습니다.

DB Server는 같이 작업한 백엔드 팀원의 계정이였기에 EC2 볼륨이 크기를 늘려줄 것을 요청하게 되었고, 문제는 해결되게 되었습니다.

🤩 문제를 해결하며 느낀 점

이번 문제는 원인을 찾기가 굉장히 어려웠습니다.
락을 획득하지 못하고, 트랜잭션이 시간내에 처리되지 못한다는 로그를 보고 문제 해결을 시작하였기 때문에 트랜잭션의 충돌이나 전파 레벨이 문제가 되지 않을까 하면서 코드 레벨에서의 수정을 하였으나 문제는 해결되지 않았습니다.

로그의 내용만으로 에러 추적이 어려울때는, 다양한 가능성을 열어두고 문제를 파악하는 것이 문제 해결에 도움이 된다는 것을 배운 좋은 사례였던 것 같습니다.