GitHub이 세션 처리에서 흔치 않은 레이스 컨디션을 어떻게 찾고 수정했는가
(github.blog)지난 3월 8일 보안 취약점 때문에 GitHub.com의 모든 사용자를 로그아웃시켰다.
* 3월 2일 한 사용자가 로그인 했는데 다른 사용자로 인증되었다는 보고가 들어왔다. 사용자는 즉시 로그아웃했지만 이 문제를 보고했고 즉시 조사에 들어갔다. 몇시간 뒤 다른 사용자가 비슷한 이슈를 보고했다.
* 초기 조사결과 한 사용자의 세션이 보고 한 시점에 2개의 IP에서 공유된 것을 발견했다.
* 최근 인프라스트럭쳐의 변경사항을 조사한 결과 최근 로드 밸런서와 라우팅쪽을 업그레이드 했고 여기서 HTTP keepalives가 수정된 것을 발견해서 관련있어 보였지만 더 조사하다 보니 관련없는 것으로 밝혀졌다.
* 그래도 인프라스트럭쳐를 조사하는 과정에서 잘못된 세션을 받은 요청이 정확하게 같은 머신과 프로세스에서 처리되었다는 것을 알게 되었다.
* 로그를 살펴본 결과 응답 바디는 정상적이었고 쿠키만 잘못 보내주었다는 것을 알게 되었고 같은 프로세스에서 처리된 다른 사용자의 쿠키가 잘못 내려갔다. 보고된 케이스에서 하나는 두 요청이 이어진 요청이었고 다른 하나에서는 두 요청 사이에 다른 요청이 2개 있었다.
* 여기서 같은 Ruby 프로세스에서 처리된 요청간에 상태가 유출되었다는 가설을 만들었고 이것이 어떻게 가능한지 궁금해졌다.
* 최근 변경사항을 검토한 결과 성능 향상을 위해 사용자에게 활성화된 기능을 검사하는 로직을 요청을 처리하는 중에 하지 않고 일정간격으로 업데이트하는 백그라운드 스레드에서 처리하게 변경된 것을 알게 되었다. 이 스레드 세이프 동작에 조사의 초점을 맞추었다.
* GitHub.com의 메인 애플리케이션은 Ruby on Rails이고 다중 스레드에서 동작하게 작성되지 않은 많은 컴포넌트가 있다.
* 애플리케이션에서 스레드는 이미 쓰이고 있었지만 새로운 백그라운드 스레드는 예외 처리 루틴에서 예상치 못한 동작을 만들었다.
* 백그라운드 스레드에서 예외가 발생했을 때 에러 로그에는 백그라운드 스레드와 실행중인 요청의 정보가 모두 담겨있었다.
* 처음에는 관련없는 요청의 데이터가 백그라운드 스레드에서 로그로 남는 것이 내부 리포팅 문제로 발생한 불일치일 뿐이라고 생각했다.
* Rails가 요청마다 새로운 컨트롤러 객체를 생성해서 처리하므로 안정하다고 생각했다.
* 그래서 이 문제가 왜 발생했는지 여전히 명확하지 않았다.
* Rails 애플리케이션에서 Rack HTTP 서벌로 사용중인 Unicorn이 요청마다 새로운 별도의 `env` 객체를 생성하지 않는다는 것을 발견하고 돌파구가 보이기 시작했다.
* 대신 Unicorn은 요청마다 Ruby 해시를 할당하고 이를 정리(clear)한다.
* 이를 통해 백그라운드 스레드의 로그가 리포딩의 불일치가 아니라 요청 데이터가 공유된다는 것을 알게 되었다.
* 이를 레이스 컨디션을 개발환경에서 재현하려고 시도했고 상황이 발생하려면 익명 요청부터 시작해야 한다는 것을 알게 되었다.
1. 익명 요청(요청 #1)이 들어오면 에외 리포트 라이브러리에 콜백이 등록되는데 이 콜백에 Unicorn이 제공하는 Rack의 요청 환경 객체에 접근하는 Rails 컨트롤러 객체의 참조가 들어있다.
2. 백그라운드 프로세스에서 예외가 발생하면 보고하기 위해 전체 컨택스트를 복사하고 콜백도 포함되어 있다.
3. 메인 스레드에서 새로운 로그인된 요청이 시작된다.(요청 #2)
4. 백그라운드 스레드에서 예외 리포팅이 컨텍스트 콜백을 처리한다. 사용자 세션 식별자를 읽으려고 하는데 없으므로 요청 #1의 Rails 컨트롤러를 통해 인증 시스템에 요청을 보낸다. Rack이 모든 요청에서 같은 객체이므로 컨트롤러가 요청 #2의 세션 쿠키를 찾아낸다.
5. 메인 스레드에서 요청 #2가 끝난다.
6. 또다른 로그인된 요청이 들어온다.(요청 #3) 인증은 이미 완료되어 있다.
7. 백그라운드 스레드에서 컨트롤러는 Rack 환경에 있는 쿠키 jar에 세션 쿠키를 작성해서 인증을 완료한다. 이 시점에는 요청 #3을 위한 쿠키 jar다.
8. 사용자가 요청 #3의 응답을 받았지만 쿠키 jar에 요청 #2의 세션 쿠키가 작성되었으므로 요청 #2의 사용자로 인증된다.
정리하면 예외가 발생하면서 도시 요청 처리가 이 상황을 만드는 순서대로 발생하면 한 응답의 세션이 이전 응답으로 대체된다. 이는 쿠키 헤더에서만 발생했고 HTML 등의 응답은 모두 원래 인증된 사용자에 대한 데이터이다.
이 버그는 이 복잡한 상황이 모두 만들어졌을 때만 발생한다.
* 이 문제를 해결하려고 새로 도입된 백그라운드 스레드를 제거해서 3월 5일 프로덕션에 배포했다.
* 이후 Unicorn에 패치를 만들어 환경 공유가 되지 않도록 해서 3월 8일에 배포했다.
* 로그 분석후 이 문제가 드물게 발생했다는 것을 알게 되었지만 잠재적인 문제를 해결하기 위해 모든 사용자의 세션을 무효화했다.
* 문제 해결후 Unicorn 메인테이너와 협력하여 이 문제 해결을 업스트림에도 적용했다.
병렬 처리가 확실히 복잡하지요. 저도 주말 동안에 개인적인 공부를 위해서 최근에 만들었던 코드를 CPU 스레드 수만큼 병렬로 실행시켜보려다 한참 헤맸습니다. 성공하긴 했지만 제대로 된 것인지 아직도 약간 찝찝하네요.