컨트리뷰션을 하게 된 계기
작년 12월 말, 서비스의 활성 사용자 수가 연초에 비해 가파르게 오르고 있다는 소식이 들릴 즈음, 서버 중 하나에서 이슈가 하나 발생했다. 액세스 토큰을 발급하고 검증하는 서버의 레이턴시가 조금씩 오르더니 피크타임에는 얼럿 임계치를 살짝 넘기기 시작한 것이다. 해당 서버의 레이턴시가 올라가면, 앱 로그인과 함께 API 게이트웨이를 경유하는 대다수의 서비스들이 영향을 받을 수 있는 상황이었기 때문에 빠르게 원인을 찾기 시작했다.
당시에 서버와 DB 의 메트릭 중에 뚜렷한 이상치를 보인 메트릭은 없었기에 원인을 파악하기 쉽지 않았다. 다만 여러 HTTP API 중에 DB 를 사용하는 API 에 대해서만 레이턴시가 증가했기 때문에, 서버에서 사용중인 DB 클라이언트과 커넥션 풀을 용의선상에 두고 아래와 같은 의심을 하게 되었다. (* 해당 서버는 spring-webflux 서버로 개발되었고, r2dbc-mysql 클라이언트와 r2dbc-pool 기반 커넥션 풀을 사용하고 있었다.)
- DB 커넥션 풀의 커넥션 고갈로 인한 이슈일까?
- DB 클라이언트 이벤트루프의 스레드 블로킹으로 인한 이슈일까?
DB 커넥션 풀이 범인일까?
DB 커넥션 풀 내의 커넥션 고갈은 r2dbc-pool 에서 기본적으로 제공하는 메트릭과 커스텀하게 추가할 수 있는 메트릭으로 확인을 할 수 있었다. 덕분에 나중에 성능 테스트를 통해 이슈를 재현하면서 알게 되었지만, 해당 이슈는 r2dbc-pool 을 사용하면서 설정을 잘못 적용해 커넥션 풀 안에 커넥션 풀을 중첩 (nested) 으로 사용하는 바람에 발생했다. DB 커넥션 풀 내 최대 커넥션 수를 사용자가 설정한 값보다 훨씬 작은 기본값을 사용했고, 서버로 들어오는 요청 수가 늘어남에 따라 DB 커넥션 풀의 최대 커넥션 수를 모두 사용하게 되어 레이턴시가 영향을 받게 된 것이다.
DB 클라이언트 이벤트루프가 범인일까?
하지만 DB 클라이언트 이벤트루프의 스레드 블로킹은 메트릭으로 확인하기 어려웠다. r2dbc-mysql 은 reactor-netty 기반의 TCP 클라이언트 이벤트루프를 사용하지만, 이벤트루프에 대한 메트릭은 제공하지 않고 메트릭을 노출하도록 설정할 수 없었기 떄문이다. 이와 비슷하게 spring-webflux 서버는 reactor-netty 기반의 HTTP 서버 이벤트루프를 사용하는데, 메트릭을 노출하도록 설정한면 아래와 같이 이벤트루프 내 작업 큐 개수 (pending task) 를 메트릭으로 확인할 수 있다.
그렇다면 왜 spring-webflux 에서는 메트릭을 노출할 수 있는데, r2dbc-mysql 에서는 할 수 없었을까?
DB 클라이언트의 어디가 문제여서 메트릭이 안보일까?
reactor-netty 에서 제공하는 HttpServer, HttpClient, TcpServer, TcpClient 등의 클래스는 모두 Fluent Builder 패턴을 따라 서버 또는 클라이언트에 메트릭을 설정할 수 있다. spring-webflux 에서는 HttpServer 를 사용하기 때문에, 아래와 같이 커스텀하게 빈을 추가하면 서버 메트릭을 노출할 수 있다.
r2dbc-mysql 에서는 TcpClient 를 사용하지만, spring-webflux 와 달리 외부에서 의존성 주입 (DI) 방식으로 TcpClient 인스턴스를 변경할 수 있는 방법이 없다. 만약 메트릭을 노출할지 여부를 외부에서 파라미터로 전달한다면, r2dbc-mysql 의 Client 인터페이스 내에서 TcpClient.metrics(true) 와 같이 설정해 클라이언트 메트릭을 노출할 수 있을 것이다.
하지만 테스트를 위해 r2dbc-mysql 라이브러리 코드를 IDE 에서 직접 수정해 확인할 수는 없다. 다른 방법이 있을지도 모르지만, 로컬 에서 r2dbc-mysql 라이브러리 프로젝트 코드를 수정한 뒤에 빌드하고, .jar 파일을 내 프로젝트로 복사한 뒤에 다시 내 프로젝트를 빌드해 확인해보는 방법을 시도해보기로 한다. 만약 로컬에서 변경한 라이브러리 코드로 클라이언트 이벤트루프 메트릭 노출에 성공한다면, r2dbc-mysql 에 컨트리뷰션도 가능할지 모른다!
로컬에서 라이브러리 코드 빌드하고 테스트하기
먼저 로컬에 r2dbc-mysql 프로젝트를 git clone 으로 내려받은 뒤에, intellij IDEA 로 프로젝트를 열고 코드를 수정한다. 메트릭을 설정하기 위해선 라이브러리 코드에 TcpClient.metrics(true) 1줄만 추가하면 된다.
그리고 이 프로젝트는 Maven 기반이므로 maven package 명령어로 빌드를 시도하면, target 디렉토리 아래에 .jar 파일이 생성된다. 테스트를 스킵하지 않고 빌드를 할 경우 testcontainers 를 활용해 도커 컨테이너 통신 테스트 코드를 실행하는데, 다행히 로컬에서 이슈없이 테스트를 통과하고 빌드에 성공했다.
이제 이 파일을 내 프로젝트로 복사한 뒤, build.gradle 에서 복사한 .jar 파일을 기반으로 빌드할 수 있도록 수정해야 한다. 기존에 Maven 저장소로부터 의존성을 가져오기 위해 implementation("io.asyncer:r2dbc-mysql:1.3.1") 와 같이 설정했다면, 이제 로컬 파일로부터 의존성을 가져오도록 implementation(files("libs/r2dbc-mysql-1.3.2-SNAPSHOT.jar")) 와 같이 설정해야 한다.
그리고 다시 프로젝트를 빌드한 뒤 실행해보면, 이제 다음과 같이 TcpClient 의 클라이언트 이벤트루프 메트릭을 확인할 수 있다! 각 메트릭은 TcpClient 가 활용하는 TcpResources 내 EventLoopGroup 에 포함된 각 이벤트루프의 처리해야할 작업 (pending task) 을 의미한다. macos 기반 로컬에서 실행했기 때문에 NioEventLoopGroup 구현체에 포함된 이벤트루프 (만약 리눅스 기반 서버에서 실행한다면 EpollEventLoopGroup 구현체에 포함된 이벤트루프) 이고, 따라서 reactor-tcp-nio-* 와 같은 이름을 갖게 된다.
메트릭 계산의 한계
처리해야할 작업 (pending task) 개수가 어떻게 수집되는지 좀 더 자세하게 살펴보자.
reactor.netty.eventloop.pending.tasks 메트릭은 MicrometerEventLoopMeterRegistrar 에서 Gauage 타입으로 메트릭을 등록한다. MicrometerEventLoopMeterRegistrar.registerMetrics() 를 보면 파라미터로 넘어온 싱글스레드로 동작하는 이벤트루프에 대해서, 이벤트루프의 작업 큐 내 원소의 개수를 조회해 메트릭으로 노출한다.
조금 더 중요하게 봐야한다고 생각하는 부분은 '언제 메트릭을 계산하는지' 이다.
MicrometerEventLoopMeterRegistrar.registerMetrics() 는 유일하게 TransportConfig.TransportChannelInitializer.initChannel() 에서만 호출되는데, DB 클라이언트의 입장에서 MySQL 서버와 소켓 연결 시 netty 의 채널이 초기화가 될 때 같이 호출된다. 다시 말하면 r2dbc-mysql 이 DB 서버와 소켓 연결 후 커넥션을 맺을 때만 메트릭이 계산된다는건데, 만약 DB 커넥션 풀링을 사용한다면 커넥션이 재사용될 때 이벤트루프의 메트릭을 다시 계산하지 않는다는 문제가 발생한다.
실제로 r2dbc-mysql 과 r2dbc-pool 을 함께 사용하면 커넥션 풀을 사용하면 이벤트루프의 처리해야할 작업 (pending tasks) 개수가 갱신되지 않을 수 있다. r2dbc-pool 에서는 아래 설정과 같이 커넥션 풀의 max size 를 지정할 수 있는데, DB 에 여러 번의 요청을 보내더라도 max size 만큼의 커넥션만 사용한다. 그리고 이벤트루프의 메트릭도 커넥션 풀의 max size 만큼만 계산된다. 만약 max lifetime 이나 max idletime 을 지정해 커넥션의 eviction 이 일어난다면 이벤트루프의 메트릭이 다시 계산되겠지만, 그렇지 않다면 다시는 이벤트루프의 메트릭이 계산되지 않을 수도 있다.
이 부분은 r2dbc-mysql 의 이슈이기보다, 풀링을 고려하지 않은 reactor-netty 의 TransportConfig 의 한계 또는 커넥션 사용 시마다 의 메트릭 계산을 고려하지 않은 r2dbc-pool 의 한계로 봐야할 것 같다. 만약 r2dbc-mysql 레벨에서 채널 초기화가 아닌 메시지 전송 시에 메트릭을 계산하게끔 핸들러를 추가한다면 커넥션 풀링을 사용하고도 메트릭이 갱신될 수 있겠지만, reactor-netty 의 MicrometerEventMeterRegistrar 접근 제어자가 package-private 이기 때문에 r2dbc-mysql 에서는 접근 불가능하다.
이 부분은 조금 더 고민해본 뒤, r2dbc-mysql 의 issue 에 enhancement 로 제안해보려고 한다!
(reactor-netty 에서 MicrometerEventMeterRegistrar 의 접근 제어자를 public 으로 변경하도록 요청한 뒤, r2dbc-mysql 에서 커넥션 풀링 사용자를 위해 위의 Handler 를 추가하는 제안을 하는 그림이면 가능하지 않을까 생각이 들기도 한다.)
r2dbc-mysql 에 컨트리뷰트하기
로컬에서 라이브러리 코드를 변경한 방식을 회사 프로젝트에서도 활용할 수 있지만, 앞으로 r2dbc-mysql 이 버전업이 될 때마다 매번 작업하기에는 번거롭기도 하고 라이브러리에 기여할 기회가 오는게 흔치 않기 때문에 컨트리뷰션에 도전해보기로 했다. 아래 링크는 해당 작업을 포함한 PR 링크이다.
feat: enable TcpClient metrics by rxdcxdrnine · Pull Request #298 · asyncer-io/r2dbc-mysql
Motivation: cannot check if LoopResources event loop has pending tasks with metrics. Modification: add TcpClient.metrics(true) with if statements, check if micrometer is available. Result: expose t...
github.com
처음 PR 을 올릴 떄는 달랑 1줄의 변경만 있는 PR 을 올렸는데, 다행히도 메인테이너가 긍정적으로 보고 개선할 점을 짚어주샸다. 개선 방향에 따라 코드를 수정하고 다시 approve 를 요청하는 과정을 거칠 수 있었다.
수정한 코드에서는 2가지를 고려했는데, '빠른 실패' 와 '주석' 이다. 메트릭 노출을 위한 설정은 전제 조건 (Precondition) 을 만족하지 못한 경우, 설정하는 코드에서 빠르게 실패해 사용자가 바로 인지할 수 있도록 구현했다. 그리고 라이브러리 설정은 사용자가 README 나 도큐먼트를 보지 않고 (혹은 도큐먼트가 아예 없을 수도 있고) 적용하는 경우가 많기 때문에, 주석도 꼼꼼하게 작성하려고 노력했다.
PR 이 main 브랜치에 merge 된 뒤에는, 메인테이너가 바로 코드가 적용된 새 버전의 릴리즈를 올려주셨다! 보통 GitHub 에서 릴리즈 페이지를 볼 떄는 라이브러리 버전이 언제 바뀌었는지, 어떤 기능이 추가됐는지 찾아보기 위해 보는 경우가 많았는데, 여기에 내 멘션이 달리니 굉장히 신기한 경험이었다.
후기
DB 클라이언트 이벤트루프에 대기중인 작업이 있는지 확인하기 위한 메트릭이 이슈를 해결하는데 직접적인 도움이 되지는 않았지만, 문제를 해결하는 과정에서 새로운 시도를 해보고 비슷한 이슈가 발생했을 때 대비하기 위한 컨트리뷰션까지 완료했다는 데에서 자신감을 얻을 수 있었다. 앞으로도 좋은 컨트리뷰션 기회가 온다면 도전해볼 생각이다!