Post

Mariadb metadata lock으로 인해 발생한 장애, 그 후의 이야기

이전 글에서 이야기한 Mariadb metadata lock으로 인해 발생한 장애의 이후 방지를 위해 이후에 어떤 것들을 했고 어떤 시행착오를 거쳤는지 이야기해보고자한다.

Body

가장 먼저 한 일은 장애가 발생한 일시, 영향을 받은 서비스, 발생 원인, 복구 과정 그리고 예방책으로 구성된 회고록을 작성했다. 당시의 장애 상황에 대해서 전체적으로 정확히 인지하지 못했거나 장애 상황에 사내에 계시지 않았던 팀원 분들에게도 정확한 내용을 공유할 필요가 있었다.

다음은 동일한 원인으로 인지하지 못한 상태에서 장애가 재발하지 않도록 사내에서 공유되어 사용되던 Datagrip의 공통 설정 파일의 수정 필요성을 알렸다. manual 설정을 사용하는 경우 lock(data lock, metadata lock)에 대해서 무지한 상태 또는 auto commit 활성화에 적응되어 트랜잭션 종료가 습관화되지 않았다면 쉽게 장애를 유발할 수 있지만 실수로 DML을 수행하더라도 쉽게 롤백 할 수 있다. 반대로 auto 설정을 사용하는 경우 세션에서 락을 해제하지 않는 상황은 발생하지 않고 마찬가지로 명시적인 트랜잭션을 수행하여 안전하게 DML을 수행할 수 있지만 실수로 DML이 커밋 되었을 때는 롤백 하는 것이 어려울 수 있다.

이는 개발자의 성향에 따라 개인마다 어떤 설정이 안전할지는 다르겠지만 팀에서는 slave DB에서는 DML을 수행하지 않고 master DB에서는 DML을 수행할 수 있기 때문에 slave DB의 설정은 auto로 변경하고 master DB의 설정은 manual으로 유지하는 것이 더 안전하다고 생각되어 채택되었다. Datagrip을 사용하지 않고 다른 클라이언트를 사용하는 일부 개발자 또는 기획자분들에게는 auto commit 옵션 활성화 여부를 확인하실 수 있도록 가이드를 드렸다.

다음은 장애가 쉽게 발생할 수 없는 환경을 만들기 위해 데이터베이스 락 관련 시스템 변수와 현재 적용되어 있는 값에 대해서 파악하고 적절한 값을 조사하여 적용했다. 현재는 데이터베이스를 생성하고 나서 시스템 변수를 변경하지 않아 초기에 설정된 기본 값을 사용해왔고 팀에서는 우리 서비스에 맞지 않는 값으로 설정되어 있거나 장애를 방지할 수 없는 설정들에 대해서도 조사하고 변경할 필요성을 느꼈다.

lock-system-variable-research-comment

장애와 직접적으로 관련이 있는 시스템 변수들 (lock_wait_timeout, wait_timeout)을 파악하고 락 관련 시스템 변수들 중 기존 값에서 변경이 필요하거나 유지해도 되는 변수들 그리고 해당 사항이 없는 변수들을 구분하여 적절한 값을 제안드렸다.

제안 드린 값이 채택되어 적용하는 방향으로 가게 되었고 wait_timeout 값의 변경으로 애플리케이션 데이터베이스 커넥션 풀의 설정 변경이 동반되어야 했다.

dbcp-configuration-research

애플리케이션에서 사용 중인 커넥션 풀(tomcat jdbc, hikari jdbc)에 따라 변경되는 데이터베이스 시스템 변수 값에 적합한 커넥션 풀 설정의 적절한 값을 결정하고 적용 대상을 파악했다.

그 후에 데이터베이스 시스템 변수와 커넥션 풀의 설정을 변경 적용했다. 팀에서는 개발 서버에 먼저 적용해 보고 1 ~ 2주간 모니터링 후에 운영에 적용하는 방향으로 결정했다.

모니터링 과정에서 확인된 현상이 있었는데 로컬 환경에서 디버깅을 하는 경우에 커넥션이 끊겨 쿼리나 커밋 또는 롤백에 실패하는 경우가 빈번하게 발생했다. 이는 디버깅 과정이 길어지면서 커넥션이 sleep 상태로 설정한 wait_timeout을 초과하여 발생했기 때문에 정상적인 현상이라고 판단하였다.

또 다른 현상은 커넥션 풀에서 커넥션을 획득했으나 커넥션이 끊긴 상태인 경우가 있었는데 로컬 환경에서 변경된 커넥션 풀 설정이 진행 중인 feature 브랜치가 병합되지 않아 wait_timeout보다 커넥션 풀의 수명 또는 검사주기가 더 길게 설정된 상태에서 발생했기 때문에 코드가 병합되면 해결되는 문제라고 판단하였다.

그렇게 개발 서버에서 1~2주간 모니터링을 진행하면서 문제가 없다고 판단되어 운영에 적용하게 되었고 적용 직후에는 문제가 발생하지 않았지만 퇴근 후 오후 7시쯤 데이터베이스 커넥션 끊김이 발생하여 요청이 실패하는 현상이 잠시 동안 발생했다.

dbcp-connection-closed-alert

최초에 조회 결과를 엑셀 파일로 다운로드하는 요청(비동기)이 실패한 후에 동일 시간대에 이어지는 요청이 실패하는 것으로 보아 엑셀 파일 다운로드 요청의 실패가 마치 다른 요청에도 영향을 미치는 것으로 보였다.

datadog-apm-long-transaction-api-trace long-transaction-excel-download-method

엑셀 다운로드를 처리하는 로직은 많은 데이터량으로 인해 수행 시간이 길어 비동기로 수행하고 있는데 이때 다운로드 처리에서 트랜잭션을 불필요하게 길게 사용하면서 커넥션 끊김 현상이 발생하였고 메소드를 리턴하는 과정에서 트랜잭션 AOP가 커밋을 요청하면서 예외가 발생한 것이다. 그런데 다른 요청들에서 커넥션이 끊길 이유가 없었고 이 요청이 마치 다른 요청에 영향을 주는 것 같아 엑셀 다운로드를 다시 요청해 보니 동일한 현상이 발생했다.

커넥션이 끊긴 요청이 다른 요청들에 영향을 주어 커넥션이 끊기는 현상이 동일하게 발생할 수 있는 상황을 가정해 보았다. 끊긴 커넥션을 커넥션 풀에 반환하고 그 커넥션을 다른 요청들이 다시 획득하여 사용하면 이러한 현상이 발생할 수 있겠다는 생각이 들었다. 커넥션 끊김 현상을 재현할 수 있는 코드를 만들어서 테스트해 보니 커넥션이 끊긴 동일한 커넥션을 사용함으로써 요청이 실패하는 동일하는 현상이 발생했다.

tomcat jdbc에서는 testOnBorrow, testOnReturn이라는 설정 옵션이 존재하는데 각각 커넥션 풀에 커넥션을 획득하고 반납할 때 커넥션이 유효한지 검증하는 여부를 의미한다. testOnReturn을 지정하지 않아도 이미 끊긴 커넥션을 반납하는 방식으로 동작할 것이라고는 전혀 생각하지 못했고 tomcat jdbc를 사용하는 애플리케이션에서는 해당 옵션들을 설정하지 않아 기본 값인 false로 적용되었고 커넥션이 끊기더라도 검증 없이 커넥션 풀에 반납되었던 것이다. 반납된 끊긴 커넥션은 timeBetweenEvictionRunsMillis에 설정된 주기마다 커넥션 검증을 수행하는 스레드에 의해 제거된다. 반면 hikari jdbc는 기본적으로 커넥션 풀에서 커넥션을 획득 할 때 커넥션을 검증하기 때문에 별도의 설정이 필요하지 않았다.

tomcat jdbc 설정에서 testOnBorrow를 활성화하기로 하고 롱 트랜잭션 로직 개선과 설정 적용 전까지는 변경한 데이터베이스 wait_timeout 시스템 변수 값을 롤백 하여 조치하기로 하였다. 하지만 엑셀 다운로드 요청이 다시 인입되어 커넥션 끊김 에러가 발생하였고 끊긴 커넥션 재사용으로 인해 요청 실패가 이어졌다. wait_timeout을 기존 값으로 되돌리면 엑셀 다운로드 요청과 같은 롱 트랜잭션에서도 커넥션 끊김이 발생하지 않을 것이라고 생각했지만 예상과는 달랐다.

mysql-global-system-variable-manual

wait_timeout 설정이 마치 적용되지 않은 것처럼 동작하여 메뉴얼을 확인해 보니 전역 시스템 변수를 변경하더라도 변경 후 연결되는 세션부터 변경이 적용된다는 것을 알게 되었다. testOnBorrow을 활성화하고 배포하여 끊긴 커넥션이 재사용되지 않도록 적용했고 재기동 과정에서 커넥션 풀의 커넥션들이 롤백한 wait_timeout 값을 기준으로 생성되어 임시 조치를 할 수 있었다. 롱 트랜잭션 로직을 개선한 후에 wait_time을 다시 180s으로 변경할 수 있었고 문제가 발생하지 않았다.

이전에 발생한 장애 이후에 원인을 제거하고 재발 방지를 위한 예방책을 적용했다. 그리고 그 과정에서 시행착오를 겪기도 했다. 예방책을 적용하기 전에 미리 파악이 잘 되어 깔끔하게 적용되었으면 좋았겠다는 아쉬움은 남아있지만 그래도 내가 발생시킨 장애에 대한 최소한의 책임을 지게 되어서 다행이라고 생각하고 팀에서 그럴 수 있는 기회를 주어서 너무 감사한 마음이 들었다. 이런 경험들을 꼼꼼하고 겸손해지는 계기로 삼아 앞으로는 나 자신이 더 안정적인(?) 개발자가 되었으면 좋겠다.

스프링 부트 2.0 버전 이후에는 hikari jdbc가 기본 데이터베이스 커넥션 풀로 채택되었고 나도 2.0 버전 이상을 사용해왔기 때문에 tomcat jdbc에 대해서는 이해도가 높지 않은 상태였다. 이번에 tomcat, hikari jdbc에 대해서 조사를 하면서 조금 더 이해할 수 있었고 hikari가 왜 널리 사용되고 있는지 공감할 수 있었다. mysql에 대해서도 조사하면서 많은 공부가 되었다. 앞으로는 장애내고 공부하지 말고 미리미리 공부해두어야겠다.

그래도 팀원들이 장애 원인과 예방책에 대해서 관심을 갖고 질문을 많이 해줘서 장애가 꼭 나쁜 점만 있는 것은 아니라는 생각이 들었다. 장애를 통해서 팀원들이 경험을 했고 개발자는 경험으로 성장한다고 생각하기 때문이다. 팀원들의 성장은 곧 팀의 역량이 향상되는 것과 마찬가지다.

This post is licensed under CC BY 4.0 by the author.