Cómo GitHub encontró y corrigió una rara condición de carrera en el manejo de sesiones

El pasado 8 de marzo, GitHub cerró la sesión de todos los usuarios de GitHub.com debido a una vulnerabilidad de seguridad.

• El 2 de marzo llegó un reporte de un usuario que inició sesión pero fue autenticado como otro usuario. El usuario cerró sesión de inmediato, pero reportó el problema y se inició la investigación enseguida. Unas horas después, otro usuario reportó un problema similar.

• La investigación inicial encontró que la sesión de un usuario se había compartido desde 2 direcciones IP en el momento reportado.

• Al investigar cambios recientes en la infraestructura, descubrieron que recientemente habían actualizado el balanceador de carga y el enrutamiento, y que allí se habían modificado los HTTP keepalives, por lo que parecía relacionado, pero tras seguir investigando se confirmó que no tenía relación.

• Aun así, durante la investigación de la infraestructura descubrieron que las solicitudes que recibieron la sesión incorrecta fueron procesadas exactamente en la misma máquina y proceso.

• Al revisar los logs, descubrieron que el cuerpo de la respuesta era normal y que solo se había enviado mal la cookie, y que se había entregado por error la cookie de otro usuario procesado en el mismo proceso. En uno de los casos reportados, ambas solicitudes fueron consecutivas, y en el otro hubo 2 solicitudes entre ambas.

• A partir de esto, formularon la hipótesis de que había una fuga de estado entre solicitudes procesadas por el mismo proceso de Ruby, y se preguntaron cómo podía ser posible.

• Al revisar cambios recientes, descubrieron que, para mejorar el rendimiento, la lógica que revisa qué funciones están habilitadas para el usuario se había cambiado para ejecutarse no durante el procesamiento de la solicitud, sino en un hilo en segundo plano que se actualizaba a intervalos regulares. La investigación se enfocó en el comportamiento thread-safe de este hilo.

• La aplicación principal de GitHub.com está hecha en Ruby on Rails, y tiene muchos componentes que no fueron escritos para funcionar en múltiples hilos.

• Ya se usaban hilos en la aplicación, pero el nuevo hilo en segundo plano generó un comportamiento inesperado en la rutina de manejo de excepciones.

• Cuando ocurría una excepción en el hilo en segundo plano, el log de errores incluía tanto la información del hilo en segundo plano como la de la solicitud en ejecución.

• Al principio pensaron que el hecho de que datos de solicitudes no relacionadas quedaran registrados desde el hilo en segundo plano era solo una inconsistencia producida por el sistema interno de reportes.

• Consideraban que Rails era seguro porque crea un nuevo objeto controlador para cada solicitud.

• Por eso, seguía sin quedar claro por qué ocurría este problema.

• Empezaron a ver una pista al descubrir que Unicorn, usado como servidor HTTP Rack en la aplicación de Rails, no crea un nuevo objeto env separado por cada solicitud.

• En cambio, Unicorn asigna un hash de Ruby por solicitud y luego lo limpia (clear).

• Gracias a esto, entendieron que el log del hilo en segundo plano no era una inconsistencia del sistema de reportes, sino que los datos de la solicitud sí se estaban compartiendo.

• Intentaron reproducir esta condición de carrera en el entorno de desarrollo y descubrieron que, para que ocurriera, tenía que comenzar con una solicitud anónima.

1. Llega una solicitud anónima (solicitud #1) y se registra un callback en la librería de reportes de excepciones; ese callback contiene una referencia al objeto controlador de Rails que accede al objeto de entorno de solicitud de Rack provisto por Unicorn.

2. Ocurre una excepción en el proceso en segundo plano y, para reportarla, se copia todo el contexto, incluido el callback.

3. En el hilo principal comienza una nueva solicitud autenticada. (solicitud #2)

4. En el hilo en segundo plano, el sistema de reporte de excepciones procesa el callback de contexto. Intenta leer el identificador de sesión del usuario, pero como no existe, envía una solicitud al sistema de autenticación a través del controlador de Rails de la solicitud #1. Como Rack usa el mismo objeto para todas las solicitudes, el controlador encuentra la cookie de sesión de la solicitud #2.

5. En el hilo principal termina la solicitud #2.

6. Llega otra solicitud autenticada. (solicitud #3) La autenticación ya está completa.

7. En el hilo en segundo plano, el controlador completa la autenticación escribiendo la cookie de sesión en el cookie jar del entorno Rack. En ese momento, ese es el cookie jar de la solicitud #3.

8. El usuario recibe la respuesta de la solicitud #3, pero como en el cookie jar se escribió la cookie de sesión de la solicitud #2, queda autenticado como el usuario de la solicitud #2.

En resumen, si ocurre una excepción y el procesamiento de las solicitudes se da exactamente en este orden, la sesión de una respuesta se reemplaza por la de una respuesta anterior. Esto solo ocurría en el encabezado de cookies; la respuesta como HTML y demás seguía conteniendo datos del usuario originalmente autenticado.

Este bug solo ocurría cuando se daban todas estas condiciones complejas.

• Para resolver este problema, eliminaron el hilo en segundo plano recién introducido y lo desplegaron en producción el 5 de marzo.

• Después crearon un parche para Unicorn para evitar que el entorno se compartiera, y lo desplegaron el 8 de marzo.

• Tras analizar los logs, descubrieron que este problema ocurría rara vez, pero invalidaron las sesiones de todos los usuarios para corregir cualquier posible impacto.

• Después de resolver el problema, colaboraron con el maintainer de Unicorn para aplicar la corrección también upstream.

[kunggom]

El procesamiento en paralelo sin duda es complicado. Yo también pasé un buen rato atorado el fin de semana cuando intenté ejecutar en paralelo, según la cantidad de hilos de CPU, un código que había hecho recientemente para estudiar por mi cuenta. Al final lo logré, pero todavía me queda la ligera inquietud de si realmente quedó bien.