Loading Likes...

Ya sabéis que no tenemos miedo de exponer públicamente nuestras vergüenzas y hoy queremos seguir haciéndolo.

En habitissimo nos equivocamos mucho. Creemos que si no cometemos errores es porque no estamos haciendo las cosas bien, no estamos yendo suficientemente rápido. No medimos la calidad por la falta de errores, sino por la capacidad de reaccionar rápidamente ante ellos. ¡Hay que equivocarse rápido!

Hoy queremos compartir con vosotros el último error que hemos cometido. Vamos a hacer público un pequeño análisis post mortem de una incidencia que ocurrió el pasado martes 11 de octubre. Como toda buena historia de terror empieza mientras prácticamente todo el equipo se encuentra lejos de su puesto de trabajo… ¡Allá vamos!

 

Post Mortem del 11/08/2016

14:20. La mitad del equipo se encuentra comiendo. Llegan algunos errores aislados desde la web a nuestro Sentry, los errores tienen esta pinta:

Error conection timed out en Sentry

Son unos pocos errores aislados que inicialmente atribuimos al proveedor de hosting que había realizado un cambio en su hardware de red hacía menos de 24 horas.

14:25. No llegan más errores. Parece todo estable.

14:50. Recibimos un aviso por parte de los compañeros del equipo de atención al cliente España. Tienen problemas para acceder a la página web. A su vez empiezan a llegarnos muchos más errores. Algo falla.

Un vistazo más detallado a los errores que recibimos nos da una idea de dónde mirar:

Unable to open PDO connection [wrapped: SQLSTATE[HY000] [1040] Too many connections]

En seguida comprobamos que, efectivamente, el servidor maestro de base de datos tiene demasiadas conexiones activas. Muchas de esas transacciones están bloqueadas.

mysql2
Gráfico de transacciones en base de datos

14:55. Identificamos múltiples consultas al servidor de base de datos que llevan más de dos minutos ejecutándose. No sabemos quién está ejecutando esas consultas. Las empezamos a matar para que el servicio vuelva a la normalidad.

15:00. Encontramos el origen de las consultas que se quedan colgadas. Cuando un usuario agrega una nueva foto a un álbum se notifica a todos los seguidores del álbum. Esas notificaciones está saturando las conexiones de base de datos.

album_image
Proceso de añadir una foto a un álbum desde la web

La notificación que enviamos se encola como una tarea en Beanstalk para realizarse de manera asíncrona. En este momento todavía no sabemos la causa exacta. Procedemos a pausar la cola afectada para que no se ejecuten nuevas tareas y seguimos investigando.

beanstalk

15:15. Identificamos el causante del problema. En la notificación a los seguidores mostramos un bloque con álbumes relacionados.

Álbumes relacionados

Para obtener los esos álbumes se realiza una consulta que cruza todas las fotos del álbum que se está siguiendo con cualquier álbum que contenga también esa foto. En función del número de fotografías y la popularidad de las fotos, esa consulta SQL puede acabar convirtiéndose en un monstruo.

15:20. En estos momentos observamos que un usuario ha estado añadiendo varias fotos a un álbum con más de 500 fotos y más de 30 seguidores. Su comportamiento coincide con los problemas en la web.

Imágenes añadidas al álbum 17596

Cada vez que el usuario añade una foto se encola una tarea para notificar a cada uno de los seguidores. La base de datos recibe más de 1.500 consultas altamente costosas en pocos minutos. El sistema está dimensionado para que las tareas asíncronas puedan realizar consultas de unos pocos segundos sin problemas. No estábamos preparados para consultas de más de dos minutos. Llegamos rápidamente a ocupar el máximo de 300 conexiones simultáneas configurado en nuestra base de datos. El servidor empieza a rechazar algunas conexiones.

Durante ese intervalo algunas peticiones a la web se han respondido con un error 500 al no poder establecer la aplicación una conexión con la base de datos.

15:30. El programador de esa funcionalidad vuelve de comer. Se le pone al día y se pone a trabajar en una solución.

15:50. Se corrige el código de la funcionalidad. A partir de ahora solo tendremos en cuenta las últimas 20 imágenes añadidas al álbum para buscar sus álbumes relacionados.

commit bce154576aabf3fac8aac3dc6fc01dada324825a
Date:   Tue Oct 11 15:50:41 2016 +0200
 
--- a/Habitissimo/External/AlbumJack.php
+++ b/Habitissimo/External/AlbumJack.php
@@ -22,6 +22,8 @@ class AlbumJack extends BaseJack {
         ORDER_BY_IMAGE_COUNT     = 1,
         ORDER_BY_SUBSCRIBERS     = 2;
 
+  const MAX_RELATED_ALBUM_IMAGES = 20;
+
   public function save(Entity $album=null)
   {
     $hab_album = new HabAlbum;
@@ -126,14 +128,18 @@ class AlbumJack extends BaseJack {
 
   public function getRelatedAlbumsByAlbumId($album_id, $discard_user_id=0)
   {
+    $image_ids = HabAlbumImageQuery::Create()
+                  ->filterByAlbumId($album_id, Criteria::EQUAL)
+                  ->orderByCreatedAt(Criteria::DESC)
+                  ->limit(self::MAX_RELATED_ALBUM_IMAGES)
+                  ->select([HabAlbumImagePeer::IMAGE_ID])
+                  ->find()
+                  ->toArray();
+
     $hab_albums =
       (array) HabAlbumQuery::create()
         ->useHabAlbumImageQuery('album_image')
-          ->useHabFileQuery()
-            ->useHabAlbumImageQuery()
-              ->filterByAlbumId($album_id, Criteria::EQUAL)
-            ->endUse()
-          ->endUse()
+          ->filterByImageId($image_ids, Criteria::IN)
           ->filterByAlbumId($album_id, Criteria::NOT_EQUAL)
         ->endUse()

16:00. Se despliega el código en todos los servidores y se reanudan las colas de Beanstalk. El problema ha quedado solucionado.

 

Conclusiones

En habitissimo desplegamos docenas de nuevas funcionalidades y correcciones cada semana a varios países distintos. Esta necesidad nos ha obligado a implantar varias herramientas y procesos que nos permitan reaccionar rápidamente: sistemas de monitorización, deploy en un paso, tests unitarios, revisión de código, etc.

Al contrario de lo que puede parecer ir rápido no está reñido con hacer las cosas bien. En nuestro caso las buenas prácticas han aparecido como una respuesta natural a ser capaces de adaptarnos rápidamente a cualquier cambio.

Desde el equipo técnico queremos agradecer a Sami el amor que nos ha demostrado. Gracias a su pasión por habitissimo y a su cariño por nuestro contenido fuimos capaces de detectar y solucionar una funcionalidad implementada sin tener en cuenta el rendimiento. Sami, si lees esto mándanos un correo y te enviamos una camiseta.


¿Te ha interesado este artículo? ¿Te gustaría hacer cosas similares y ayudarnos a mejorar? Echa un vistazo a nuestras ofertas de empleo 😉
 

 

Loading Likes...

4 thoughts on “Cómo una fan de habitissimo produjo una caída del servicio

  1. Buenísimo el relato Bruce! Lo he sentido en vivo y en directo y he recordado situaciones parecidas 🙂
    Coml dices, lo bueno es encontrar la falla, solucionarlo rápido y tomarlo con humor (y unas birras).
    Un abrazo al equipo.

  2. Un indicio claro de que hay errores de arquitectura. Os hace falta una visión transaccional. Un control de sistemas que, por mucho que falle un programador, nunca se hunda el servicio.

    1. Gracias por el aporte Jaume!

      Nuestra plataforma es joven y ha crecido mucho en poco tiempo. Por la manera de trabajar que tenemos preferimos que los programadores tengan influencia sobre los sistemas (paradigma DevOps). Anteponemos una arquitectura flexible en la que podamos hacer cambios de manera ágil y equivocarnos rápido a una infraestructura blindada de errores.

      No considero que lo descrito en el post sea evidencia de un error en el diseño de la arquitectura, más bien es que todavía no hemos priorizado añadir controles como el que comentas. Todavía nos queda mucho camino y muchas cosas por mejorar 🙂

Deja un comentario

Tu dirección de correo electrónico no será publicada. Los campos obligatorios están marcados con *