고백부터 하겠다
우리 시스템은 한동안, 어떤 로그인을 남의 이름으로 기록하고 있었다. B가 로그인했는데 기록에는 A가 남는 식으로. 먼저 말해두면 이 결함은 원인 규명과 수정이 끝난 '과거 사례'다. 그러니 이 글은 취약점 공지가 아니라 부검 기록 — 사고의 경위와 원인, 재발 방지책을 남기는 포스트모템이다. 시리즈 이름에 SQL이 붙어 있지만 이번 범인은 SQL이 아니다. 그래도 이 시리즈가 계속 쫓아온 것이 '데이터와 기록'이라면, 기록 그 자체가 거짓말을 한 사건만큼 이 자리에 어울리는 이야기도 없다.
지난 글은 이런 질문으로 끝났다. “다음 범인을 만났을 때, 정황 증거 말고 목격자의 진술을 내밀 수 있는가.” 6년 묵은 데이터가 누구 손에 만들어졌는지 끝내 알 수 없었던 그 사건 이후, 내가 운영에 참여하는 시스템(농산물 생산 이력을 추적하는 규제 산업 시스템 — '누가 무엇을 했는가'라는 기록이 남달리 무거운 곳이다)에 그 목격자를 세우는 공사가 시작됐다. 감사 로그, 누가 언제 무엇을 바꿨는지를 남기는 기록이다.
감사 로그를 '어떻게' 세웠는지는 다른 글의 몫이다. 오늘의 이야기는 공사 도중에 벌어진 일이다. 목격자는 완공되기도 전에 첫 진술을 했고, 그 진술이 가리킨 건 우리 자신이었다.
이상한 기록 한 줄
감사 로그를 붙여가는 과정에서 이상한 기록 하나가 눈에 걸렸다. 어떤 로그인 기록의 행위자(actor)가 틀려 있었다. 실제 로그인한 사용자는 B인데, 기록에는 A로 남아 있었던 것이다.
제일 먼저 의심한 건 방금 만든 감사 로그 코드였다. 당연한 순서다 — 시스템에서 가장 최근에 태어난 코드가 가장 유력한 용의자니까. 기록이 틀렸다면 기록기가 고장 났다고 보는 게 상식이다. 그런데 기록기는 결백했다. 받은 값을 받은 그대로 적고 있었다. 문제는 '받은 값'이었다.
행위자 이름은 감사 로그가 지어내는 게 아니라 SecurityContext에서 꺼내온다. SecurityContext — 스프링 시큐리티가 '지금 이 요청의 사용자가 누구인지'를 담아두는 상자다. 그러니까 기록이 틀린 게 아니라, 상자 안에 틀린 사람이 들어 있었다.
그런데 B의 로그인 요청 어디에도 A를 상자에 넣을 코드는 없다. 넣은 사람이 없는데 값이 있다. 가능한 답은 하나뿐이다 — '전부터 들어 있던 것이 남아 있었다.' 전부터라니, 대체 어디에?
채우기만 하고, 비우지 않았다
이 시스템의 인증은 JWT 토큰 방식이다. 요청 헤더에 실려온 토큰을 필터가 검증하고, 통과하면 사용자 정보를 SecurityContext에 담는다. 실제 코드 대신 구조만 옮긴 개념 예제로 보면 이렇다.
// 개념 예제: 문제가 됐던 구조
public class JwtFilter extends OncePerRequestFilter {
@Override
protected void doFilterInternal(HttpServletRequest request,
HttpServletResponse response, FilterChain chain)
throws ServletException, IOException {
String token = resolveToken(request);
if (token != null && validate(token)) {
Authentication auth = buildAuthentication(token);
SecurityContextHolder.getContext().setAuthentication(auth); // 상자를 채운다
}
chain.doFilter(request, response);
// ...그리고 아무것도 하지 않는다. 비우는 코드가 없다.
}
}
우리 필터가 이 모양이었다. 요청이 끝날 때 SecurityContextHolder.clearContext()를 호출하지 않았다. 채우기만 하고 비우지 않은 것이다.
“안 비우면 뭐가 문제지? 요청이 끝나면 스레드도 같이 사라질 텐데.” 나도 오랫동안 그렇게 알고 있었다. 이 문장의 뒷부분이 틀렸다는 게 이 사건의 전부다.
스레드는 퇴근하지 않는다
톰캣 같은 서블릿 컨테이너는 요청이 올 때마다 스레드를 새로 만들지 않는다. 미리 만들어둔 스레드 묶음, 즉 스레드풀에서 하나를 꺼내 요청을 맡기고, 끝나면 없애는 게 아니라 풀에 반납해서 다음 요청에 다시 쓴다. 스레드 생성 비용을 아끼는 모든 서버의 표준 전략이다.
그리고 그 상자가 보관되는 곳이 ThreadLocal이다. ThreadLocal — 같은 변수라도 스레드마다 자기만의 값을 갖게 해주는, 말하자면 호텔 객실마다 하나씩 딸린 '개인 금고'다. 요청 처리 중 어느 계층에서든 “지금 사용자 누구지?”라고 물으면 답이 나오는 스프링 시큐리티의 편리함이 여기서 온다. 지금 일하는 스레드의 금고만 열면 되니까. API는 세 줄이면 전부다.
// 개념 예제: ThreadLocal의 전부
static ThreadLocal<String> safe = new ThreadLocal<>();
safe.set("투숙객 A의 신분증"); // 지금 이 스레드의 금고에만 들어간다
safe.get(); // 같은 스레드가 열면 A의 신분증, 다른 스레드가 열면 null
safe.remove(); // 금고 비우기 — 이 한 줄이 이 글 전체의 주인공이다
두 사실을 겹치면 유령이 태어난다. 금고는 스레드의 것이고, 스레드는 요청이 끝나도 죽지 않는다. 그러면 금고 속 내용물도 죽지 않는다.
호텔로 옮기면 이렇다. 객실(스레드)은 투숙객(요청)이 바뀌어도 그대로 남는다. 체크아웃 때 객실 금고(ThreadLocal)를 비우는 건 청소(clearContext)의 몫인데, 우리 호텔에는 청소가 없었다. A가 쓰고 나간 객실에 B가 들어왔더니, 금고에 A의 신분증이 그대로 들어 있었던 것이다.
B의 로그인에 A가 남기까지
이제 사건을 재구성할 수 있다.
- 사용자 A의 요청이 스레드 T에서 처리된다. JWT 필터가 A의 인증 정보를 T의 금고에 채운다. 요청이 끝나고 T는 풀로 반납된다 — 금고는 그대로.
- 사용자 B가 로그인 요청을 보낸다. 로그인 요청에는 아직 토큰이 없다. 토큰을 '받으러 가는' 요청이니까. 그래서 필터는 금고를 새로 채우지 않고 지나간다.
- 하필 이 요청이 스레드 T에 배정된다. 처리 중 누군가 “지금 사용자 누구지?”라고 물으면, 금고는 A라고 답한다.
- 그렇게 B의 로그인이 A의 이름으로 기록된다.
핵심은 '필터가 금고를 채워주지 않는 요청'이다. 그런 요청에서 만들어지는 기록에는 이전 투숙객이 흘러들 수 있다. 이 그림은 유령이 왜 하필 로그인 기록에서 목격됐는지도 설명해준다. 토큰을 들고 오는 보통의 요청에서는 필터가 매번 진짜 사용자를 금고에 덮어쓴다 — 유령이 남아 있었더라도 흔적부터 지워지는 것이다. 유령이 모습을 드러내는 건 토큰 없이 도착하는 요청, 대표적으로 로그인 그 자체다. 게다가 B가 하필 A가 쓰던 스레드를 배정받아야 하니, 풀에 스레드가 수십 개라면 이건 확률 게임이다. 평소에는 재현되지 않다가 어쩌다 한 번 남의 이름이 찍힌다. 이런 잔존 버그가 오래 사는 이유다.
확률 게임은 조건을 조이면 결정적 재현으로 바뀐다. 로컬에 재현 서버를 만들고 server.tomcat.threads.max=1로 스레드를 하나로 줄였다 — 스레드가 하나면 모든 요청이 같은 금고를 쓴다(재현에서는 토큰 검증을 헤더의 사용자명으로 단순화했다). 첫 요청에 사용자 alice를 실어 보내고, 두 번째 요청은 인증 헤더 없이 '지금 나는 누구인가'를 물었다. 답은 user=alice. 두 응답의 스레드 이름이 http-nio-...-exec-1로 똑같이 찍혀서, 같은 객실이 재사용됐다는 사실까지 출력에 남는다. 같은 실험을 수정본으로 돌리면 두 번째 응답은 user=(no authentication)이다. 재현 코드는 공부 노트 저장소의 demo 폴더에 있다.
수정: 청소를 계약서에 넣다
수정은 원인 규명에 비하면 싱거울 만큼 짧았다. 필터가 요청 종료 시 컨텍스트를 비우도록 고쳤다.
// 개념 예제: 수정 후 구조
try {
// ...토큰 검증, 컨텍스트 채우기...
chain.doFilter(request, response);
} finally {
SecurityContextHolder.clearContext(); // 무슨 일이 있어도 비운다
}
finally인 게 중요하다. 처리 중 예외가 나든 말든, 스레드가 풀로 돌아가기 전에 금고는 무조건 비워져야 한다.
변명거리가 아주 없지는 않다. 스프링 시큐리티의 표준 필터 체인에는 요청이 끝날 때 컨텍스트를 정리해주는 장치가 들어 있어서, 교과서적인 구성에서는 이 문제를 만날 일이 드물다. 하지만 인증 경로를 커스텀 필터로 직접 조립하는 순간, '비우는 책임'이 프레임워크의 규약에서 개별 코드의 몫으로 넘어온다. 그리고 넣는 코드는 기능이 안 돌아가면 티가 나니 반드시 작성된다. 비우는 코드는 없어도 당장 아무 일도 일어나지 않는다 — 스레드풀 위에서 조용히 유령이 될 뿐이다. 채우는 코드와 비우는 코드는 한 세트이고, 우리는 그 계약을 채우는 쪽만 이행하고 있었다.
반전: 목격자의 첫 공로
곱씹을수록 이상한 사건이다. 이 결함은 감사 로그보다 먼저 있었다. 공사 전에도 필터는 컨텍스트를 비우지 않았고, 유령은 그때도 있었을 것이다. 다만 아무도 보지 못했다. '누가'를 적는 기록이 없는 시스템에서, '누가'가 틀리는 버그는 증상이 없다.
감사 로그는 앞으로 일어날 일을 기록하려고 만든 도구다. 그런데 완성되기도 전에, 이미 있던 결함을 '발견하는' 도구가 됐다. 목격자를 세우자 목격자가 제일 먼저 증언한 게 우리 집 문단속이었던 셈이다.
솔직히 말하면 이런 사고는 감추고 싶어진다. '보안'이라는 단어가 붙는 순간 더 그렇다. 하지만 이 시리즈에서 계속 확인해온 것처럼 — 성능 조치의 트레이드오프를 문서에 남기고, 미뤄둔 리팩토링을 미뤘다고 적어두는 것처럼 — 기록되지 않은 사고는 팀의 지식이 되지 못하고, 지식이 되지 못한 사고는 반복된다. 다음번에는 목격자도 없이. 누가 언제 무엇을 했는지 남기자고 감사 로그를 만드는 팀이 정작 자기 사고를 기록하지 못한다면, 그 로그는 반쪽짜리다. 이 글이 그 기록이다.
재발 방지 체크리스트
같은 실수를 막기 위해 남긴 목록이다.
- ThreadLocal을 채우는 코드를 봤다면, 비우는 코드가 어디 있는지 짝으로 확인하자. 없다면 그게 버그다. 비우기는 try/finally로 — 예외가 나도 스레드는 풀로 돌아간다.
- '요청의 끝'과 '스레드의 끝'을 구분하자. 스레드풀 위에서 이 둘은 다른 사건이고, 그 틈에 상태가 산다.
- 커스텀 인증 필터를 쓴다면 청소 책임이 누구에게 있는지 확인하자. 표준 필터 체인 밖에서 직접 채우는 코드는 정리도 직접 해야 한다.
- 스레드를 넘기는 코드도 의심하자. @Async, 스케줄러, 별도 ExecutorService — 스레드풀은 톰캣에만 있는 게 아니다. ThreadLocal은 논리 흐름이 아니라 스레드를 따라간다. 다른 풀로 일을 넘겼다면, 그 풀의 금고 정리는 누가 하는지도 물어야 한다.
- 이상한 로그를 '로그 버그'로 단정하고 지우지 말자. 기록기보다 값의 출처를 먼저 추적하자 — 이상 기록은 소음이 아니라 신호일 수 있다.
- 잔존이 의심되면 스레드풀을 1개로 줄여 테스트하자. 확률 게임이 결정적 재현으로 바뀐다. 잔존 버그는 평소엔 스레드 개수 뒤에 숨는다.
마치며: 유령은 기록 앞에서만 보인다
ThreadLocal도 스레드풀도 매일 그 위에서 일하면서, 정작 계약서를 읽어본 적 없는 도구였다. 이 사건 이후로 스레드에 붙는 상태를 볼 때마다 두 가지를 묻게 된다. 누가 채우는가, 누가 비우는가. 오늘 하나만 해본다면 — 지금 다루는 코드베이스에서 SecurityContext를 직접 만지는 필터와 ThreadLocal에 set 하는 코드를 검색해서, 그 옆에 remove()나 clearContext()가 짝으로 서 있는지 확인해보자.
그리고 이 사건이 남긴 더 큰 확신은 기록 그 자체에 대한 것이다. 지난 사건에서는 기록이 없어 범인의 이력을 포기했고, 이번에는 기록을 세우다가 보이지 않던 결함을 잡았다. 기록은 미래의 사고를 위해 쌓는 것인 줄 알았는데, 세우는 순간부터 현재를 비춘다. 당신의 시스템은 어떤가 — 기록이 없어서 보이지 않을 뿐인 유령이, 지금 몇이나 걸어다니고 있을까. 목격자를 세우는 공사는 아직 끝나지 않았으니, 공사장에서 주운 이야기도 이것이 마지막은 아닐 것이다.