“실패한 시도도 남겨라”
내가 운영에 참여하는 시스템(농산물 생산 이력 관리, 규제 산업)의 감사 로그 요구에는 처음 들으면 갸웃하게 되는 조항이 하나 있었다. 실패한 시도도 남겨라. 로그라는 건 보통 '일어난 일'의 기록인데, 이 요구는 일어나다 만 일 — 시도됐지만 실패해서 데이터에는 아무 흔적도 남기지 못한 일 — 까지 적으라고 말한다. 규제 산업에서는 '누가 무엇을 시도했고 실패했는가'도 추적 가치가 있기 때문이다.
곱씹을수록 수긍이 갔다. 감사 로그의 진짜 시험대는 성공을 남기는 능력이 아니라, 실패를 남기는 능력이다. 그리고 그다음엔 서늘해졌다. 이 한 줄이 구현의 마지막 조각을 결정한다. 뒤에서 보겠지만 데이터베이스에는 '실패하면 전부 없던 일로 만든다'는 유서 깊은 약속이 있고, 실패한 시도의 기록은 정확히 그 약속과 충돌하기 때문이다.
시리즈로 보면 오늘은 완공식이다. 첫 글에서 grep 실측이 감사 로그의 설계도를 그렸다 — 데이터베이스라는 창고에서 쓰기는 100% JPA라는 문 하나로만 지나가니, 그 문 위에 CCTV 한 대면 된다는 것. 재귀 쿼리로 범인을 쫓던 사건에서는 목격자 없는 수사의 한계를 봤고, 지난 글은 공사 도중 터진 사고의 부검이었다. 그 글은 “목격자를 세우는 공사는 아직 끝나지 않았다”로 끝났는데 — 이제 끝났다. 완공된 건물을 한 바퀴 돌아보자. 시설은 세 개고, 마지막 방 하나가 이 글의 제목을 만든다.
정문의 방명록 — Controller AOP
투어는 정문에서 시작한다. 모든 변경은 사용자의 클릭 한 번, 즉 HTTP 요청 하나에서 출발하므로 첫 수집 지점은 요청이 건물에 들어서는 순간이다. 쓰기성 HTTP 요청(POST/PUT/PATCH/DELETE)이 도착하면 방명록을 쓴다. 구현은 Spring AOP — 특정 메서드 호출의 앞뒤에 공통 동작을 끼워 넣는 스프링 기능이다. 컨트롤러 코드는 한 줄도 건드리지 않고 진입 시점에 끼어들어 셋을 적는다. 누가(사용자), 어디로(URI), 어디서(IP). 그리고 이 방문 전체에 trace_id라는 UUID를 발급한다.
trace_id가 이 설계의 조용한 주인공이다. 클릭 한 번이 DB에서 행 하나만 바꾸리라는 보장은 없다. 한 요청에서 발생한 모든 변경을 같은 UUID로 묶어두면, 나중에 “이 클릭 한 번에 4개 행이 바뀌었다”를 그대로 펼쳐 보일 수 있다. 방명록의 서명이 이후 모든 CCTV 프레임에 함께 찍히는 셈이다.
이 방명록은 ThreadLocal — 같은 변수라도 스레드마다 자기만의 값을 갖게 해주는 저장소 — 에 보관한다. 요청을 처리하는 동안 어느 계층에서든 '지금 이 요청의 방명록'을 꺼낼 수 있어야 하기 때문이다. 이 단어에 뒷목이 서늘해진다면 지난 글을 읽은 독자다. 채우는 코드와 비우는 코드가 한 세트라는 수업료는 그 사건으로 이미 치렀다.
방명록이 준비됐으니, 이제 카메라다.
쓰기 문 위의 CCTV — Hibernate Interceptor
첫 글에서 예고했던 바로 그 카메라다. Hibernate Interceptor는 Hibernate가 INSERT/UPDATE/DELETE SQL을 실행하기 직전에 끼어들 수 있도록 열어둔 저수준 훅인데, 콜백 세 개를 구현하면 쓰기 문을 지나는 모든 것이 찍힌다.
INSERT를 잡는 onSave와 DELETE를 잡는 onDelete는 직관 그대로다. 백미는 UPDATE를 잡는 onFlushDirty다. 이름부터 풀자. JPA는 트랜잭션 안에서 엔티티 객체의 변경을 지켜본다 — 이 감시가 더티 체킹이고, 감시하며 쌓인 변경분을 SQL로 만들어 DB에 내보내는 순간이 flush다. onFlushDirty는 바로 그 flush 시점에 호출되면서 엔티티의 '이전 상태'와 '현재 상태'를 나란히 넘겨준다. 둘을 비교하면 바뀐 필드만 골라 before/after diff를 만들 수 있다.
강조할 것은 카메라의 위치다. 비즈니스 코드 수정 0줄. 저장 로직 어디에도 '감사 로그를 남겨라'라는 문장이 없다. 카메라는 문 위에 다는 것이지, 지나다니는 사람들 주머니에 하나씩 넣는 게 아니다. 첫 글의 실측이 “쓰기는 전부 이 문으로 지나간다”를 보증했기에 가능한 배치다.
다만 완공 검수에서 제일 놓치기 쉬운 게 뒷문이다.
뒷문의 보완 카메라 — @Modifying AOP
인터셉터에는 구조적인 사각지대가 있다. @Modifying 벌크 쿼리 — 여러 행을 SQL 한 방으로 UPDATE/DELETE하는 방식 — 는 영속성 컨텍스트(JPA가 객체의 변경을 감시하는 작업대)를 거치지 않고 곧장 DB로 간다. 엔티티가 로드되지 않으니 더티 체킹도 없고, flush 이벤트도 없다. 인터셉터의 콜백은 아예 호출되지 않는다. CCTV 화각 바깥으로 난 뒷문인 셈이다.
이 뒷문이 몇 개인지는 이미 세어둔 상태였다. 첫 글의 grep 실측 — 리포지토리 31개에 흩어진 49건. 그래서 여기는 별도의 AOP로 보완했다. @Modifying 메서드 호출을 가로채, 정문에서 발급된 같은 trace_id에 기록을 잇는다. 사각지대는 없애는 게 아니라 좌표를 알고 보완하는 것이고, 그 좌표는 실측이 미리 지도에 그려둔 것이었다.
여기까지가 수집이다. 세 지점이 모은 기록은 요청이 끝나는 시점에 — 성공이든 실패든, 상태와 에러 메시지를 달아 — 한 번에 저장된다. 이제 투어의 마지막 방, 기록 보관소다.
기록 보관소 — 회로를 분리한 이유
트랜잭션부터 짚자. 트랜잭션은 여러 SQL을 '전부 성공 아니면 전부 취소'라는 하나의 작업 단위로 묶는 것이고, 이 전부-아니면-전무의 성질을 원자성(atomicity)이라 부른다. 출금만 되고 입금은 안 되는 세계를 막아주는, 데이터베이스의 가장 오래된 약속이다. 기초와 동시성 이야기는 예전에 트랜잭션과 동시성에서 다뤘다.
그런데 이 약속이 감사 로그에는 정반대로 작동한다. 시나리오를 굴려보자. 사용자가 저장 버튼을 누른다. 비즈니스 로직이 행 몇 개를 바꾸고, 인터셉터는 충실히 기록을 모은다. 그리고 마지막 검증에서 예외가 터져 롤백된다. 원자성은 약속대로 트랜잭션 안의 모든 것을 없던 일로 만든다 — 감사 기록의 INSERT까지 포함해서. 실패를 기록해야 하는데, 실패가 기록을 지운다. 기록할 가치가 가장 높은 사건일수록 기록은 가장 확실하게 증발한다. 이건 버그가 아니다 — 원자성은 자기 일을 완벽하게 하고 있다. 목격자를 사건과 같은 배에 태우면, 배가 가라앉는 순간 진술도 함께 가라앉는 것뿐이다.
답은 기록을 다른 배에 태우는 것이다. 비행기의 블랙박스를 떠올리면 빠르다 — 블랙박스가 기체와 운명을 같이한다면 존재할 이유가 없다. 추락에서도 살아남으라고 일부러 따로 만든 장비다. 스프링에서 이 분리를 표현하는 언어가 트랜잭션 전파(propagation) — 이미 트랜잭션이 열려 있는 상태에서 또 @Transactional 메서드를 만나면 어떻게 할지 정하는 규칙이다. 기본값 REQUIRED는 “이미 있으면 합류한다”, 말하자면 합승이다. 그리고 REQUIRES_NEW는 바깥 트랜잭션을 갓길에 잠시 세워두고(suspend) 차를 새로 뽑아 따로 달리는 것이다. 실제 저장 메서드는 이 한 조각이다(원문 발췌).
@Transactional(propagation = Propagation.REQUIRES_NEW)
public void flush(AuditContext ctx, AuditStatus status, String errorMessage) {
// 비즈니스 트랜잭션과 별개의 새 트랜잭션에서 audit 행들을 저장
repository.saveAll(rows);
}
이름이 같아 헷갈릴 수 있는데, 이 flush는 Hibernate의 flush가 아니라 요청 동안 모아둔 감사 기록을 비워내 저장하는 우리 쪽 메서드다. 시그니처를 다시 보자. status와 errorMessage — 이 메서드는 처음부터 성공만 받을 생각이 없다. 누가 무엇을 시도했고, 왜 실패했는지까지 받아 적는 그릇이다. 이 안에서 저장되는 audit 행들은 자기만의 트랜잭션에서 자기만의 커밋을 갖는다. 본 트랜잭션이 곧이어 롤백되더라도, 이미 커밋된 기록은 지워지지 않는다. 건물로 옮기면 기록 보관소의 전기 회로를 본 건물에서 분리한 것이다. 본 건물이 차단기를 내려도(롤백) 보관소의 불은 꺼지지 않는다.
말로는 깔끔하다. 하지만 이런 건 눈으로 봐야 믿긴다.
재현: 롤백에서 살아남는 행
재현 데모를 만들었다. 이 시리즈의 데모 코드와 출력은 영어로 쓴다 — 실행 캡처가 모든 언어판 글에서 재사용되기 때문이다. 구조는 사건의 뼈대만 남겼다. 비즈니스 저장 하나, 감사 기록 하나, 강제 예외 하나 — 그리고 감사 저장의 전파 설정만 다른 시나리오 두 벌이다. 아래는 데모 소스 그대로다.
@Transactional
public void attemptWithNewTxAudit() {
repo.save(new BusinessRecord("order-2"));
audit.recordNewTx("CREATE", "FAILED", "boom");
throw new RuntimeException("boom"); // business transaction rolls back
}
// Scenario B: opens its OWN transaction — the real system's choice.
// Survives even when the caller rolls back.
@Transactional(propagation = Propagation.REQUIRES_NEW)
public void recordNewTx(String action, String status, String error) {
repo.save(new AuditLog(action, status, error));
}
시나리오 A는 recordNewTx 대신 기본 전파(REQUIRED)의 recordSameTx를 부르는 것만 다르다. 실행 출력에서 로그 메시지 부분만 그대로 옮기면 이렇다 (타임스탬프 포함 전체 출력은 아래 캡처에).
### Scenario A — audit record joins the SAME transaction (default propagation)
business call failed: boom (transaction rolled back)
rows after A: business=0, audit=0 <- the audit record died with the rollback
### Scenario B — audit record in its OWN transaction (REQUIRES_NEW)
business call failed: boom (transaction rolled back)
rows after B: business=0, audit=1 <- the audit record survived
surviving audit row: action=CREATE, status=FAILED, error=boom
[/code]
Scenario A가 바로 아무 생각 없이 붙이면 만나는 기본 동작이다. 감사 저장 코드를 성실하게 짜놓고도, 정작 남겨야 할 실패의 순간마다 기록이 증발한다. 전체 재현 코드는 공부 노트 저장소의 demo 폴더에 있다.
다만 이 옵션은 공짜가 아니다.
원자성을 깨는 값
REQUIRES_NEW를 쓰기로 했다면 청구서 세 장을 같이 받아야 한다.
첫째, 커넥션 2개. '중단(suspend)'은 반납이 아니다. 바깥 트랜잭션은 자기 커넥션을 쥔 채 멈춰서 기다리고, REQUIRES_NEW는 커넥션 풀에서 새 커넥션을 하나 더 꺼낸다. 바깥 트랜잭션이 살아 있는 시점에 호출된다면, 그 순간 요청 하나가 커넥션 두 개를 점유하는 것이다. 풀에 여유가 있을 때는 문제가 아니지만, 풀이 말라붙은 상황에서는 모두가 첫 커넥션을 쥔 채 두 번째 커넥션을 기다리는 최악의 정체로 번질 수 있다. 풀 크기와 감사 지점의 개수는 같이 계산해야 한다.
둘째, self-invocation 함정. @Transactional은 스프링이 빈을 프록시(원본을 감싼 대리 객체)로 감싸 메서드 호출을 가로채는 방식으로 동작한다. 그래서 같은 클래스 안에서 자기 메서드를 부르면 프록시를 거치지 않고, REQUIRES_NEW는 에러 한 줄 없이 무시된다 — 새 트랜잭션 대신 조용히 본 트랜잭션에 합류해버린다. 평소엔 멀쩡히 저장되다가, 하필 롤백이 나는 날에만 기록이 같이 사라진다. 롤백 테스트를 돌려보기 전까지는 티도 안 난다. flush 같은 메서드를 반드시 별도 빈으로 분리해 프록시 바깥에서 호출해야 하는 이유다.
셋째, 원자성을 깨는 결정 그 자체. REQUIRED가 기본값인 데는 이유가 있다. 대부분의 코드에서 전부-아니면-전무는 버그를 막아주는 방패고, 트랜잭션을 쪼개는 순간 그 방패를 스스로 내려놓는 것이다. 반대 방향의 질문도 함께 떠안는다 — 감사 저장 쪽이 실패하면 본 업무는 어떻게 할 것인가. 원자성을 어디서 끊을지는 패턴이 아니라 요구사항이 정한다. 우리의 요구는 '실패한 시도도 남긴다'였고, 그래서 끊었다.
완공 검수
재귀 쿼리 사건은 이런 질문으로 끝났었다. “다음 범인을 만났을 때, 정황 증거 말고 목격자의 진술을 내밀 수 있는가.” 이제 답할 수 있다. 정문의 방명록이 클릭 한 번마다 trace_id를 찍고, 쓰기 문의 CCTV가 바뀐 필드의 before/after를 남기고, 뒷문의 보완 카메라가 벌크 쿼리 49건을 커버하고, 보관소는 본 건물과 회로가 분리돼 있어 롤백 정전에도 불이 꺼지지 않는다. 그 사건에서 6년 묵은 행을 앞에 두고 끝내 포기했던 질문 — 누구의 손으로, 왜 — 가 이제부터는 답을 갖는다. 비즈니스 코드 수정 0줄, 수집 지점 3개, 트랜잭션 분리 1개. 이게 완공 명세의 전부다.
이 공사에서 얻어갈 것을 하나만 고르라면 전파를 외우는 법이다. 옵션을 표로 외우면 금방 잊는다. '이 기록은 본 작업과 운명을 같이해야 하는가'라는 질문 하나로 기억하면 REQUIRED와 REQUIRES_NEW는 다시 찾아볼 일이 없다. 같이 죽어야 하면 합류, 혼자 살아남아야 하면 분리. 덧붙여 트랜잭션과 원자성, COMMIT/ROLLBACK은 SQLD의 단골이기도 하다 — 정리는 공부 노트의 트랜잭션 편에 있다.
투어를 마치며 돌아보니, 남은 방이 하나 있긴 하다. 이 모든 기록이 최종적으로 눕는 자리 — 테이블 그 자체다. 롤백에서도 살아남는 기록이라면, 그 기록이 쌓일 테이블도 그만큼 진지하게 지어야 하지 않을까. 그런데 그 테이블은 누가 설계하지? 적어도 ddl-auto는 아니었다.