jobs 테이블에 락 경합이 있다는 이야기가 있어 SHOW ENGINE INNODB STATUS 로 실시간으로 들여다보고 원인을 하나 짚어 보고했다. 그것이 맞느냐는 지적을 받고 다시 보니 처음 짚은 것은 락이 퍼진 경로였지 락이 오래 잡힌 이유가 아니었다.
Table of contents
Open Table of contents
문제 — 원인과 전파 경로의 혼동
처음 낸 결론은 idx_status_run_at 에서의 갭 락 연쇄였는데 그것은 락이 번져 나간 통로였다. MySQL 8.0 매뉴얼은 갭 락을 인덱스 레코드 사이의 틈에 거는 락으로 설명하므로 범위를 잠근 트랜잭션이 오래 살면 그 틈에 넣으려는 다른 트랜잭션이 줄줄이 기다린다. 애초에 락이 길게 유지된 이유는 다른 곳에 있었다.
원인과 전파 경로를 섞어서 보면 통로를 막는 대책이 나오고 근본은 그대로 남는다. 둘을 갈라야 어느 쪽을 고쳐야 하는지가 정해진다.
관측 1 — 잠자는 트랜잭션이 쥔 락
다시 조사하며 관측한 첫째는 트랜잭션이 외부 호출 도중에도 열려 있다는 것이었다. information_schema.INNODB_TRX 에서 trx_state 가 RUNNING 이고 쿼리는 없는데 trx_rows_locked 가 수십인 세션이 몇 분씩 남아 있었다.
코드를 보니 DB::transaction() 안에서 lockForUpdate() 로 행을 잠그고 외부 인터페이스를 호출한 뒤 결과를 갱신하고 있었다. 상대가 느려지면 그 지연만큼 락이 그대로 잡혀 있는 구조였다.
관측 2 — 한 행에 몰린 갱신
둘째는 categories 의 특정 행 하나에 수십 개의 스레드가 동시에 갱신을 시도하는 상황이었다. 배치가 여러 갈래로 퍼지지만 결국 같은 상위 항목의 has_pending 플래그를 건드린다.
여기까지가 그 순간의 스냅샷이고 둘 다 실제로 관측한 사실이다. 문제는 이 관측에서 곧바로 시스템의 근본 원인이라는 결론으로 건너뛴 것이었다.
검증 — 자릿수가 다른 누적 통계
같은 세션에서 performance_schema.table_lock_waits_summary_by_table 을 보니 그림이 완전히 달랐다. 문제의 jobs 는 SUM_TIMER_WRITE 가 수십 초 수준이고 categories 는 상위 목록에도 없었다.
지배적인 병목은 내가 보지도 않은 order_histories 였고 자릿수가 아예 달랐다. 실시간으로 본 두 경합은 누적으로 보면 거의 없는 수준이었으므로 조사 시점에 마침 그랬을 뿐일 수 있었다.
결론 — 관측과 해석과 판단의 분리
그렇다고 관측이 무의미한 것은 아닌데 트랜잭션 안에서 외부 호출을 하는 것은 그 자체로 문제다. 지금 지배적이지 않을 뿐 상대가 느려지면 그때 병목이 된다.
두 가지 방법이 있었는데 처음 보고를 고쳐 결론만 바꾸는 것과 보고를 관측과 해석과 판단으로 나눠 다시 쓰는 것이다. 뒤쪽을 골랐다. 이유는 결론만 바꾸면 무엇이 스냅샷이고 무엇이 누적인지가 또 섞여서다. 대신 보고가 길어지고 결론 한 줄을 원하는 쪽이 끝까지 읽어야 하는 것을 감수했다. 관측은 사례 확인이고 해석은 시점 스냅샷이며 판단은 안티패턴 자체는 검토 대상이되 이 관측만으로 구조 문제를 결론짓지 말라는 것이었다.
정리
- 그 순간 본 경합이 시스템의 병목이 아닐 수 있다
- 원인과 전파 경로를 섞지 않는다
lockForUpdate()뒤에 외부 호출을 하면 지연만큼 락이 잡힌다INNODB_TRX스냅샷과performance_schema누적을 함께 본다- 스냅샷만 보면 우연을 원인으로 만든다
- 누적만 보면 왜 그런지 알 수 없다
- 지배적이 아니어도 안티패턴은 검토 대상이다
- 보고를 관측과 해석과 판단으로 나누면 약한 곳이 드러난다