ParityPay로 검증하는 결제 정합성 2 - 잠금을 필요 이상으로 오래 쥐고 있었다: 추론을 측정으로 바꾼 기록

1편에서 잔액 비음수(INV-003)를 조건부 원자 UPDATE로 강제한다고 썼다. 이 글은 그 UPDATE가 동시 결제 아래에서 어떻게 동작했는지, 느려진 원인을 “안다”고 생각했던 것이 어디까지 측정이고 어디부터 추론이었는지, 그리고 측정 방법 자체가 결론을 만들 뻔한 두 번의 실수를 정리한 기록이다. 수치는 전부 실측값이고, 측정 조건과 설명하지 못한 것도 그대로 적는다.

시작: 잠금 전략을 고르는 벤치마크가 엉뚱한 것을 재고 있었다

잔액 차감은 두 방식이 후보였다. SELECT ... FOR UPDATE로 행을 잠그고 계산해서 저장하는 비관적 잠금, 그리고 WHERE available_amount >= :amount AND version = :v를 조건으로 하는 단일 UPDATE. 둘 다 구현하고 같은 조건에서 비교했다. 지갑 하나에 8 스레드 × 5 결제, 워밍업 1회 후 3회 측정, 전략을 번갈아 실행.

구현	median	min~max	초과 승인
비관적 잠금	2,133 ms	1,998~2,311 ms	0건
조건부 원자 UPDATE	1,463 ms	969~1,975 ms	0건

정확성이 같다는 점이 먼저다. 어느 쪽도 잔액을 넘겨 승인하지 않았고 최종 잔액은 0원이었다. 성능 차이는 그다음이고, 편차가 3.3배까지 벌어지는 환경(개발 노트북 + Docker)이라 median 차이를 신호로만 썼다.

이 비교에서 배운 것이 하나 더 있었다. 첫 번째 비교에서는 조건부 UPDATE만 JPA @Modifying 경로였고 비관적 잠금은 JDBC였다. 결과가 반대로 나왔다. 두 구현을 JDBC로 맞추자 결과가 뒤집혔다. 첫 비교가 재고 있던 것은 잠금 전략이 아니라 JPA의 flush·clear 비용이었다. 비교 조건을 맞추기 전의 숫자는 해석할 가치가 없었고, 이 교훈은 뒤에서 두 번 더 반복된다.

P-002: 원인을 “안다”고 적었지만 추론이었다

HTTP 부하로 같은 지갑에 20 VU를 몰았더니 서로 다른 지갑에 줄 때보다 처리량이 5.8배 떨어지고 p95가 8.7배가 됐다. 보고서에 이렇게 적었다. “잔액 행 잠금이 직렬화 지점이다.”

그럴듯하고 아마 맞을 것이다. 하지만 그 실험은 애플리케이션 바깥에서 응답 시간만 봤다. DB CPU, 락 대기, slow query 어느 것도 보지 않았고, 보고서 자신이 “pg_stat_statements를 켜지 않았다”고 적어두고 있었다. 이 문장은 측정이 아니라 추론이었다.

추론이 틀렸을 가능성은 여럿 있었다. 커넥션 풀 앞에서 줄을 서고 있을 수도 있고, 잠금이 아니라 I/O일 수도 있고, 잔액 UPDATE가 아니라 다른 문장이 느린 것일 수도 있다. “원인을 안다”와 “원인을 쟀다”는 다르고, 다음 조치가 무엇이어야 하는지는 후자만 알려준다.

M-007: 세 가지를 함께 봐야 답이 갈린다

서버 안쪽을 보기로 했다. 하나만 봐서는 답이 갈리지 않아서 세 가지를 같이 켰다.

보는 것	답하는 질문
pg_stat_statements	어느 문장이 시간을 쓰는가. 경합에서 그 문장의 평균 실행 시간이 얼마나 늘어나는가
pg_stat_activity 10ms 샘플링	백엔드가 무엇을 기다리는가. 행 잠금인가, I/O인가, 애플리케이션인가
HikariCP pending	줄이 DB 앞이 아니라 커넥션 풀 앞에 서는 것은 아닌가

샘플러는 DB 서버 안에서 돌렸다. docker exec 왕복이 수십 ms라 클라이언트에서는 10ms 간격을 만들 수 없기 때문이다. 측정 창은 20 VU가 유지되는 구간 안쪽 34초만 썼다. 램프업이 섞이면 평균이 흐려진다.

결과 1. 추론은 맞았다. 동일 지갑에서 대기 표본의 약 84%가 잔액 행의 Lock(transactionid 75~77%, tuple 8%)이었고, 압도적으로 잔액 UPDATE에서 기다리고 있었다. 같은 부하를 서로 다른 지갑에 주면 Lock 대기는 0.0%이고, 대신 표본의 75%가 Client:ClientRead, 즉 DB가 애플리케이션의 다음 문장을 기다리는 시간이었다. 잔액 UPDATE의 평균 실행 시간은 0.3ms에서 97.4ms가 됐다. 다른 문장들은 변화가 없었다.

결과 2. 줄은 커넥션 풀 앞에 서지 않는다. 모든 실행에서 hikaricp_connections_pending의 최댓값이 3이고 active는 20에 붙어 있었다. 병목은 풀 크기가 아니라 그 너머다. 풀을 키우는 것은 답이 아니다.

여기까지면 “추론이 맞았다”로 끝나는 실험이다. 그런데 같은 측정이 아무도 보지 않던 것을 하나 드러냈다.

결함 I: 31ms 트랜잭션 중 17ms를 잠근 채, 실제로 일한 시간은 2.31ms

부하 없이 결제 한 건을 문장 단위로 찍었다(log_min_duration_statement = 0).

경과	실행	문장
0.0 ms	0.026 ms	BEGIN
1.0 ms	0.241 ms	INSERT idempotency_record
8.0 ms	0.051 ms	SELECT wallet
14.0 ms	0.071 ms	UPDATE wallet_balance — 여기부터 지갑 행 잠금
18.0 ms	0.061 ms	INSERT ledger_account
24.0 ms	0.096 ms	INSERT outbox_event
25.0 ms	0.106 ms	UPDATE idempotency_record
26.0 ms	0.070 ms	INSERT ledger_transaction
27.0 ms	0.210 ms	INSERT ledger_entry
28.0 ms	0.205 ms	INSERT ledger_entry
30.0 ms	0.575 ms	INSERT payment
31.0 ms	0.761 ms	COMMIT — 잠금 해제

잔액 UPDATE가 14ms 지점에서 행을 잠그고, COMMIT이 31ms에 그 잠금을 푼다. 잠금 보유 17ms. 그 안에서 DB가 실제로 문장을 실행한 시간을 다 더하면 2.31ms다. 나머지 86%는 DB가 애플리케이션의 다음 문장을 기다린 시간이고, 같은 지갑의 다른 결제는 그 시간을 전부 기다린다.

원인은 코드 순서였다. 결제 승인 유스케이스가 잔액을 먼저 차감하고, 그 뒤에 원장 계정 해석, 분개 전기, 결제 저장, Outbox 기록, 멱등 확정을 했다. 행 잠금은 COMMIT까지 풀리지 않으므로 뒤따르는 열두 문장과 커밋 fsync가 전부 잠금 안에서 일어난다.

변경 전  |---- 잠금 없음 14ms ----|======== 잠금 보유 17ms (DB 실행 2.31ms) ========| COMMIT
변경 후  |------------ 잠금 없음 ~26ms ------------|== 잠금 4~7ms ==| COMMIT

차감을 앞에 둘 이유가 없었다. 잔액이 부족하면 트랜잭션 전체가 롤백되므로 결과는 같다. 앞에 두면 거절 경로에서 헛일을 덜 하고, 뒤에 두면 잠금을 덜 쥔다. 경합이 없을 때의 헛일보다 경합이 있을 때의 직렬화가 훨씬 비싸다. 차감을 트랜잭션의 마지막으로 옮겼다. 취소 경로도 같은 모양이었고 더 길었다(48ms 중 28ms). 둘 다 옮겼다.

왜 이제야 보였는가. 응답 시간만 보면 “경합이 있으니 느리다”로 끝난다. 잠금을 언제부터 언제까지 쥐는지는 문장 단위 로그를 봐야 나온다. 옳은 진단(잔액 행이 직렬화 지점)이 그 다음 질문(그 행을 얼마나 오래 쥐는가)을 덮고 있었다.

변경 후 같은 자리를 다시 찍었다. 잠금 보유 17ms → 4~7ms. 동일 지갑 20 VU 부하에서:

	변경 전	변경 후
결제 처리량	183.5/초	320.9/초 (1.75배)
결제 p95	274 ms	144 ms
취소 처리량	114.6/초	215.4/초 (1.88배)
취소 p95	189 ms	99 ms

INV-003은 여전히 조건부 원자 UPDATE와 DB CHECK가 지킨다. 잠금 전략도 그대로다. 바꾼 것은 순서뿐이다.

측정 방법이 결론을 만들 뻔했다

변경 전후 비교에서 처음에는 두 빌드를 순차로 쟀다. 변경 전 3회, 그다음 변경 후 3회. 결과는 경합이 없는 대조군까지 4.8배 빨라졌다는 것이었다.

코드가 설명할 수 없는 숫자다. 차감 순서를 바꾸는 것은 경합이 있을 때만 의미가 있고, 서로 다른 지갑에 주는 부하에는 아무 영향이 없어야 한다. 의심이 들어 같은 변경 전 빌드를 나중에 다시 돌리니 처음보다 4.5배 높은 값이 나왔다. 처음 측정이 잰 것은 코드가 아니라 기계 상태였다. 첫 3회를 돌리는 동안 같은 기계에서 다른 프로젝트의 컨테이너와 JVM이 돌고 있었다.

이후 모든 비교는 반복마다 순서를 뒤집어 번갈아 돌린다. 변경 전 → 변경 후 → 변경 후 → 변경 전. 기계 상태가 한쪽 빌드에만 유리하게 작용하는 것을 막기 위해서다.

그러고도 대조군이 1.30배 움직였다(598.9 → 779.1/초). 경합이 없으면 이 변경은 아무것도 바꾸지 않아야 한다. 두 지표가 서로 다른 말을 했다. 전체 승인 건수로 보면 반복별 차이가 +0.8%, +38%, +10%로 들쭉날쭉하고, 측정 창 기준으로 보면 +19.6%, +30%, +17%로 일관됐다. 이 차이의 원인은 밝히지 못했고, 그대로 적었다. 경합이 없는 경로가 빨라졌다고는 주장하지 않는다. 확실한 것은 경합 경로이며, 그것은 세 반복 모두 같은 방향이었고 직접 측정한 기전(잔액 UPDATE 평균이 절반, 잠금 보유가 짧아짐)과 일치한다.

M-010: 처리량으로 두 번 실패하고, 문장 순서로 확정했다

잠금 보유가 4~7ms에서 0에 가까워지지 않은 이유가 있었다. 남은 구간은 Hibernate가 커밋 시점에 flush하는 쓰기였다. ledger_transaction, ledger_entry 두 건, payment INSERT는 JPA가 관리하므로, 코드에서 아무리 앞에 불러도 실제 문장은 커밋 직전에 나간다. 코드 순서와 문장 순서가 다르다. 차감을 코드의 마지막 줄로 옮겨도 그 네 개는 여전히 차감 뒤에 실행된다.

차감 직전에 명시적으로 entityManager.flush()를 부르면 그 네 쓰기가 잠금 앞으로 나간다. 처리량으로 재봤다.

반복	변경 전 승인	변경 후 승인
1	23,634	28,210
2	6,158	23,173
3	12,729	18,703

변경 후가 세 번 모두 높았다. 그런데 이 표를 근거로 쓰지 않았다. 변경 전 조건이 6,158에서 23,634까지 3.8배 흔들렸다. 그 폭 안에서는 1.8배든 1.1배든 구분되지 않는다. 측정 창 기준으로 보면 3회 중 2회만 높았다. 두 지표가 같은 말을 하지 않았다.

되돌렸다. 근거가 이 상태인데 flush를 넣으면, 얻는 것이 불확실한 대신 제약 위반이 커밋이 아니라 그 지점에서 드러나도록 의미를 바꾸게 된다. 확실하지 않은 이득으로 치를 값이 아니었다.

두 번째 시도도 처리량으로는 판정할 수 없었다. 기계 부하 평균이 34.8이었고 다른 컨테이너 20여 개가 돌고 있었다. 이때 질문을 바꿨다. 잴 수 없는 것을 더 정밀하게 재려 하기보다, 부하에 면역인 다른 것을 재는 편이 빠르다. 한 트랜잭션 안의 문장 순서는 CPU 경합이 바꾸지 못한다.

	차감 이후의 문장	잠금 보유
flush 없음	ledger_transaction, ledger_entry×2, payment INSERT, COMMIT	26 ms
flush 있음	COMMIT뿐	1 ms

flush가 보류 쓰기 네 개를 잠금 앞으로 내보낸 것이 한 번에 보였다. 타이밍은 여전히 흔들렸지만(같은 조건 4라운드 중앙값이 4, 4, 4, 47ms 대 5, 2, 7, 2.5ms), 판정을 만든 것은 순서이지 시간이 아니었다. 적용했다. 잠금 보유가 짧아지면 동일 지갑 처리량이 오른다는 인과는 이미 1.75배, 1.88배로 재둔 상태였다.

치른 값도 있다. 원장과 결제의 제약 위반이 커밋이 아니라 flush 지점에서 드러난다. 어느 쪽이든 트랜잭션은 되돌아가지만, 예외가 지갑 어댑터에서 나오므로 원인을 읽을 때 한 번 더 짚어야 한다. INV-001은 지연 제약 트리거라 여전히 커밋 시점에 검사된다.

같은 질문을 세 번 물었는데, 앞의 두 번은 질문이 아니라 측정 방법이 틀린 것이었다.

병목은 사라지지 않았다

동일 지갑 경합의 대가는 대조군 대비 3.3배에서 2.4배로 줄었다. 사라지지는 않았다. 한 행을 고쳐야 하는 일이 직렬화되는 것은 잠금 전략이나 문장 순서의 문제가 아니라 요구사항의 성질이다. “같은 지갑의 잔액은 한 번에 하나씩만 바뀐다”는 INV-003을 지키는 방법 자체다. 줄인 것은 그 행을 쥐고 있는 시간이고, 더 필요하면 지갑 단위 직렬화나 잔액 분할이며 그것은 새 결정이다.

실무 경험과의 관계

대량 배치 안정성 시리즈에서 지분율 삭제를 청크 트랜잭션으로 쪼갠 이유 중 하나가 락 점유 시간이었고, 키 생성 병목에서 채번을 별도 트랜잭션으로 뗀 이유도 락 보유 시간을 비즈니스 로직과 무관하게 만들기 위해서였다. 원리는 같다. 잠금을 쥐는 시간을 트랜잭션 길이가 아니라 실제로 필요한 구간으로 줄인다.

다른 점은 실무에서는 응답 시간과 처리 시간이 줄어든 것을 확인하고 끝냈다는 것이다. 이 프로젝트에서는 “줄었다” 다음에 “왜 여기서 멈추는가”를 물었고, 그 질문이 JPA flush 시점이라는 두 번째 원인으로 이어졌다. 실무에서 그 질문을 던지지 않은 것이 틀렸다는 뜻은 아니다. OOM이 사라지면 그 시점에는 충분하다. 하지만 다음 병목이 어디에 있는지는 그 질문을 던져야 보인다.

정리

• “원인을 안다”와 “원인을 쟀다”는 다르다. P-002의 추론은 맞았지만, 맞았다는 것은 M-007을 돌린 뒤에야 알 수 있었고, M-007은 추론이 덮고 있던 두 번째 원인을 드러냈다.
• 잠금 보유 시간은 응답 시간에서 보이지 않는다. 문장 단위 타임라인을 찍어야 “언제부터 언제까지”가 나온다.
• 두 빌드를 순차로 재면 기계 상태를 잰다. 번갈아 돌려야 하고, 그래도 설명 안 되는 차이는 그대로 적는다.
• 처리량으로 판정할 수 없는 기계에서는 부하에 면역인 관측(문장 순서)으로 바꾼다. 판정하지 못한 실험도 결과이고, 그때는 되돌리고 숫자만 남긴다.
• 코드 순서와 SQL 순서는 다르다. JPA 아래에서는 특히 그렇다.