평균 CPU는 여유로운데, 커밋은 왜 느릴까?

안녕하세요. 토스증권 DBA Team 조규범입니다.주문과 체결을 처리하는 API 뒤에는 Oracle DB가 있습니다. 이 DB에서 커밋이 늦어지면 커밋을 기다리던 세션이 모두 함께 멈추고, API 응답도 그만큼 늦어지는데요. 거래가 몰리는 정규장 시간에는 짧은 지연도 그냥 넘기기 어렵습니다.그런데 어느 날부터 커밋 대기가 0.1초 넘게 이어지는 현상이 반복해서 보이기 시작했습니다. 스토리지, OS, 네트워크, 애플리케이션, Oracle을 차례로 확인했지만 평균 지표는 모두 정상 범위였어요. 호스트 CPU에도 여유가 있었고요.원인은 CPU 소켓 하나에 몰려 있던 NIC 인터럽트였습니다. 인터럽트를 두 소켓으로 나누자 0.1초 이상의 커밋 대기는 대부분 개선됐고, 같은 조치를 적용한 다른 Oracle RAC에서는 동시접속자가 28% 많은 날에도 개장 직후 10분간 CPU 사용률이 36.6%에서 17.4%로 내려왔습니다. 이번 글에서는 평균 지표 뒤에 가려져 있던 병목을 어떻게 찾았는지, 그리고 왜 설정이 아니라 하드웨어 배치를 바꿔야 했는지 공유하려고 합니다.그림 1. 개선 전후의 핵심 지표평균 지표로는 보이지 않던 지연커밋은 무엇을 기다릴까Oracle에서 트랜잭션을 커밋하면, 변경 내용을 담은 리두 로그가 디스크에 기록된 뒤에야 커밋이 완료됩니다. 리두 로그 기록은 LGWR(log writer)라는 백그라운드 프로세스가 전담하는데요. 세션은 LGWR가 기록을 마칠 때까지 기다리고, 이 시간은 log file sync라는 대기 이벤트로 확인할 수 있습니다.인스턴스의 커밋 기록은 모두 LGWR를 거칩니다. 그래서 LGWR가 잠깐만 밀려도 그사이 커밋한 세션이 모두 함께 기다리게 되죠. 저희가 본 현상도 이것이었습니다. log file sync 대기가 0.1초 이상 이어지는 일이 반복됐어요.지연은 특정 CPU에서만 생겼습니다다섯 개 레이어를 모두 점검했지만 특이 사항은 없었습니다. 평균으로 보면 전부 정상 범위였기 때문입니다. 지연이 간헐적으로 생기다 보니 평균에 묻혔을 수 있다고 보고, LGWR 프로세스를 더 잘게 들여다보기로 했습니다.pidstat으로 LGWR가 어느 CPU에서 실행되는지 기록해 보니 규칙이 보였습니다. 지연은 아무 때나 생기지 않았고, LGWR가 28번 CPU에서 실행될 때만 생기고 있었습니다.그림 2. pidstat으로 LGWR의 실행 CPU를 추적한 결과. 관찰 당시를 재구성한 예시로, CPU...