Como o GitHub encontrou e corrigiu uma condição de corrida rara no tratamento de sessões

Em 8 de março, por causa de uma vulnerabilidade de segurança, o GitHub.com desconectou todos os usuários.

• Em 2 de março, chegou um relato de que um usuário fez login, mas foi autenticado como outro usuário. O usuário fez logout imediatamente, mas reportou o problema e a investigação começou na mesma hora. Algumas horas depois, outro usuário relatou um problema semelhante.

• A investigação inicial encontrou que a sessão de um usuário estava sendo compartilhada por 2 IPs no momento em que foi reportada.

• Ao investigar mudanças recentes na infraestrutura, descobriram que haviam atualizado recentemente o load balancer e a parte de roteamento, e que os HTTP keepalives tinham sido modificados ali, então isso pareceu relacionado, mas uma investigação mais profunda mostrou que não tinha relação.

• Ainda assim, no processo de investigar a infraestrutura, descobriram que as requisições que receberam a sessão incorreta foram processadas exatamente na mesma máquina e no mesmo processo.

• Ao examinar os logs, descobriram que o corpo da resposta estava normal e que apenas o cookie tinha sido enviado incorretamente, e que o cookie de outro usuário, processado no mesmo processo, tinha sido enviado por engano. Em um dos casos reportados, as duas requisições eram consecutivas; no outro, havia 2 requisições entre elas.

• A partir disso, formularam a hipótese de que havia vazamento de estado entre requisições processadas pelo mesmo processo Ruby, e passaram a se perguntar como isso seria possível.

• Ao revisar mudanças recentes, descobriram que, para melhorar o desempenho, a lógica que verifica quais funcionalidades estão ativadas para o usuário deixou de ser executada durante o processamento da requisição e passou a ser tratada por uma thread em segundo plano que atualizava isso em intervalos regulares. A investigação então se concentrou no comportamento thread-safe dessa mudança.

• A aplicação principal do GitHub.com é Ruby on Rails, e há muitos componentes que não foram escritos para funcionar em múltiplas threads.

• Threads já eram usadas na aplicação, mas a nova thread em segundo plano criou um comportamento inesperado na rotina de tratamento de exceções.

• Quando uma exceção acontecia nessa thread em segundo plano, o log de erro continha tanto informações da thread em segundo plano quanto da requisição em execução.

• No início, acharam que os dados de uma requisição não relacionada aparecendo no log da thread em segundo plano eram apenas uma inconsistência causada por um problema interno de reporte.

• Como o Rails cria um novo objeto controller para cada requisição, pensaram que isso era seguro.

• Por isso, ainda não estava claro por que esse problema acontecia.

• O avanço começou quando descobriram que o Unicorn, usado como servidor HTTP Rack na aplicação Rails, não cria um novo objeto env separado para cada requisição.

• Em vez disso, o Unicorn aloca um hash Ruby para cada requisição e depois o limpa (clear).

• Com isso, perceberam que os logs da thread em segundo plano não eram uma inconsistência de reporte, mas sim evidência de que os dados da requisição estavam sendo compartilhados.

• Tentaram reproduzir essa condição de corrida no ambiente de desenvolvimento e descobriram que, para a situação ocorrer, era preciso começar com uma requisição anônima.

1. Quando chega uma requisição anônima (requisição #1), um callback é registrado na biblioteca de reporte de exceções, e esse callback contém uma referência ao objeto controller do Rails que acessa o objeto de ambiente da requisição do Rack fornecido pelo Unicorn.

2. Quando uma exceção acontece na thread em segundo plano, todo o contexto é copiado para fins de reporte, e o callback também é incluído.

3. Na thread principal, começa uma nova requisição autenticada. (requisição #2)

4. Na thread em segundo plano, o reporte de exceção processa o callback de contexto. Ele tenta ler o identificador da sessão do usuário, mas como ele não existe, envia uma requisição ao sistema de autenticação por meio do controller do Rails da requisição #1. Como o Rack usa o mesmo objeto em todas as requisições, o controller encontra o cookie de sessão da requisição #2.

5. A thread principal termina a requisição #2.

6. Chega outra requisição autenticada. (requisição #3) A autenticação já está concluída.

7. Na thread em segundo plano, o controller grava o cookie de sessão no cookie jar presente no ambiente Rack para concluir a autenticação. Nesse momento, trata-se do cookie jar da requisição #3.

8. O usuário recebe a resposta da requisição #3, mas, como o cookie de sessão da requisição #2 foi gravado no cookie jar, ele é autenticado como o usuário da requisição #2.

Resumindo, quando uma exceção ocorre e o processamento de múltiplas requisições acontece exatamente nessa sequência, a sessão de uma resposta é substituída pela da resposta anterior. Isso acontecia apenas no cabeçalho de cookie; respostas como HTML e outras continuavam contendo dados do usuário originalmente autenticado.

Esse bug só ocorria quando toda essa combinação complexa de situações era satisfeita.

• Para resolver o problema, removeram a thread em segundo plano recém-introduzida e implantaram essa mudança em produção em 5 de março.

• Depois, criaram um patch para o Unicorn para impedir o compartilhamento do ambiente e o implantaram em 8 de março.

• Após analisar os logs, descobriram que esse problema acontecia raramente, mas invalidaram as sessões de todos os usuários para eliminar qualquer risco potencial.

• Depois de corrigirem o problema, trabalharam com os mantenedores do Unicorn para aplicar a correção também no upstream.

[kunggom]

O processamento paralelo realmente é complicado. Eu também passei um bom tempo quebrando a cabeça no fim de semana tentando executar, para estudo pessoal, um código que tinha feito recentemente em paralelo, de acordo com o número de threads da CPU. Consegui, mas ainda fico um pouco com a pulga atrás da orelha sobre se ficou realmente certo.