Bugs Divertidos: Episodio I

Introducción

Hace tiempo que tenía ganas de arrancar una serie sobre el tipo de bugs que encontramos en producción en el CloudBuild Cache. Para dar un poco de contexto: nuestro equipo opera más de 40 mil máquinas en todo Estados Unidos, con más de 85 PB de capacidad de almacenamiento total, y funcionamos como capa de caché para un montón de cosas: código fuente, paquetes NuGet, artefactos de build, etc. Básicamente proveemos un caché P2P diseñado específicamente para builds dentro de CloudBuild , aunque la implementación actual no se parece en nada al paper.

La escala y la enorme cantidad de operaciones que ejecutamos termina provocando que cada rincón del código se ejecute en paralelo en distintos momentos, lo que suele generar bugs realmente interesantes. El objetivo de esta «serie» es mostrarlos para que otros puedan, con suerte, reírse un poco, quizás aprender algo (y también para que yo me vuelva más fluido escribiendo).

Para este primero, elijo uno entretenido que encontramos la semana pasada. Hay que reconocer que no es lo más descabellado del mundo, pero igual es divertido. En cualquier caso, ¡disfrutalo!

La Condición de Carrera en el Dispose

Usamos un clúster de Redis como camino rápido de bajo ancho de banda para algunos de nuestros datos. Esta instancia de Redis es bastante crítica, porque no poder obtener datos de ella significa que tenemos que esperar a que los datos se sincronicen por el camino lento de alto ancho de banda (lo que puede tardar hasta 5 minutos, frente a los pocos milisegundos que lleva hablar con Redis). Para comunicarnos con Redis, usamos el maravilloso cliente StackExchange.Redis .

La forma en que se supone que hay que usar la biblioteca se ve más o menos así:

using StackExchange.Redis;
...
// This is a cache for connections to the Redis cluster, meant to be stored and
// reused
ConnectionMultiplexer redis = ConnectionMultiplexer.Connect("localhost"); 
// Get a connection
IDatabase db = redis.GetDatabase(); 
... // Do your thing with the connection
redis.Dispose(); // Shut the cache down!

El problema es que a veces este ConnectionMultiplexer empieza a dar problemas, y las instancias que devuelve terminan siendo inutilizables. Intentamos rastrear exactamente qué estaba pasando, pero es relativamente difícil atrapar a una máquina mientras ocurre, porque con frecuencia se resuelve de la nada después de unos minutos de causar estragos.

No tener conexión a Redis puede significar para nosotros un build fallido, o peor, múltiples builds fallidos (y nos esforzamos por mantener una tasa de éxito de builds del 99,9 %, así que realmente no nos podemos dar ese lujo). Como la conexión a Redis es crítica para nosotros, decidimos implementar 2 mecanismos:

1. Si empezamos a ver las firmas de error que en el pasado correlacionaron empíricamente con un ConnectionMultiplexer roto, recrearlo después de cierta cantidad de fallos.
2. Después de recrearlo más de X veces en un período corto, simplemente forzar el reinicio del servicio.

Esto «funcionó»: vimos que esos errores dejaban de ocurrir; los reinicios del servicio eran relativamente pocos (lo que significaba que el mecanismo (1) estaba haciendo su trabajo), y todos estábamos contentos. ¡Pero esto no iba a durar!

De repente, empezamos a ver muchos ObjectDisposedException en los lugares donde usábamos la instancia ConnectionMultiplexer. La experiencia acumulada con condiciones de carrera nos hizo desconfiar naturalmente de nuestra «innovadora» estrategia de mitigación. Resulta que este fragmento de código es esencialmente todo lo que hace falta para entender qué estaba saliendo mal:

public async Task<IDatabase> GetDatabase(...) {
  if (_resetMultiplexerCts.IsCancellationRequested) {
    using (await _mutex.WaitAsync()) {
      if (_resetMultiplexerCts.IsCancellationRequested) {
        _resetMultiplexerCts = new CancellationTokenSource();
        await CloseConnectionMultiplexer(_connectionMultiplexer);
        _connectionMultiplexer = await CreateConnectionMultiplexer();
      }
    }
  }
  ...
}

En nuestro código, llamábamos a GetDatabase() para obtener del pool la conexión a Redis. Cuando surgía la necesidad de resetear las instancias ConnectionMultiplexer, básicamente lo hacíamos agregando un CancellationTokenSource:

• Cuando una operación detecta que la instancia actual está rota, llama a _resetMultiplexerCts.Cancel()
• Cualquier nueva operación que necesite usar el multiplexor lo detectaría (tal como muestra el código de arriba) y lo recrearía antes de continuar.

El patrón de las líneas 2 a 4 es un double-checked lock . La intención es que solo la primera operación que detecta que el multiplexor está roto realice el reset. Todas las operaciones que lleguen después esperarán a que se complete antes de intentar usarlo.

El gran problema aquí es el orden: recreamos el CancellationTokenSource en la línea 5. La nueva fuente no está cancelada, lo que significa que cualquier nueva operación que ocurra después de esa línea evaluará _resetMultiplexerCts.IsCancellationRequested como falso, aunque en realidad todavía no hemos creado el nuevo multiplexor (lo cual sucede en la línea 7).

Por lo tanto, podemos obtener el siguiente entrelazado:

• El hilo 1 dispara un reset haciendo _resetMultiplexerCts.Cancel()
• El hilo 2 inicia una operación, toma el lock, ejecuta hasta la línea 5 inclusive
• El hilo 3 inicia una operación, pero ve el nuevo _resetMultiplexerCts, se salta el bloque if completo de la línea 2 y toma una referencia al multiplexor antiguo sin haberlo usado todavía
• El hilo 2 continúa la ejecución cerrando el multiplexor de conexión antiguo y creando el de reemplazo
• El hilo 3 intenta usar el multiplexor antiguo, provocando un ObjectDisposedException

Como realizamos UNA CANTIDAD ENORME de operaciones de Redis por segundo, el escenario del hilo 3 se daba con más frecuencia de lo que uno esperaría. Esto se solucionó esencialmente haciendo lo siguiente:

public async Task<IDatabase> GetDatabase(...) {
  if (_resetMultiplexerCts.IsCancellationRequested) {
    using (await _mutex.WaitAsync()) {
      if (_resetMultiplexerCts.IsCancellationRequested) {
        await CloseConnectionMultiplexer(_connectionMultiplexer);
        var newMultiplexer = await CreateConnectionMultiplexer();
        Volatile.Write(ref _connectionMultiplexer, newMultiplexer);
        _resetMultiplexerCts = new CancellationTokenSource();
      }
    }
  }
  ...
}

En esencia, evitamos recrear el _resetMultiplexerCts hasta que realmente tengamos una instancia funcionando. La barrera de memoria introducida por el Volatile.Write está pensada para evitar que la asignación de _resetMultiplexerCts se reordene con la creación o asignación del nuevo multiplexor.

Se podría argumentar que este código es subóptimo en el sentido de que esperamos a que el multiplexor antiguo se cierre en lugar de simplemente crear uno nuevo y hacer el shutdown después de haber desbloqueado todas las operaciones concurrentes; pero hay que tener en cuenta que estamos lidiando con una biblioteca de terceros con estado, y desde luego no queríamos ser víctimas de bugs del tipo «ah, estamos cacheando algo al azar internamente, así que ¡BAZINGA!».