Biko2

Unicef.es y las posibilidades de Drupal 8

Hace unos meses hablábamos sobre cómo Drupal busca salir de la isla, asociarse a otros proyectos open source y de esa manera hacer el ecosistema php más consistente. La publicación de Unicef.es viene a demostrar que esto es cierto.

Drupal 8 aporta la consistencia que necesita un sector poderoso como es el de la gestión de contenidos. El desarrollo web ha cambiado y nuestros ecosistemas de software tiene que adaptarse y tener en cuenta las buenas prácticas en el desarrollo, los sistemas basados en API, el diseño “atómico/modular”, los dispositivos y sus soportes, la gestión de despliegues, y el soporte multilingüe. Y después de haber participado en el desarrollo de Unicef.es podemos confirmar que esto es así.

Desde el principio asumíamos este proyecto como un reto. Un reto compartido con KPMG, SBIT y 540. Un reto en el que hemos tenido que aprender rápidamente la potencia oculta de Drupal 8, descubrir sus grandes posibilidades y sufrir en algunos casos por su falta de madurez. Pero eso sí, podemos decir que Drupal 8 sigue siendo el mejor gestor de contenidos del mercado.

Son muchos los detalles que podríamos comentar del desarrollo y en algunos ellos profundizaremos en posteriores posts. Pero rescatamos algunos de los que nos parecen más relevantes:

  • Unicef.es  es un Drupal pensado para gestionar landigs. Se ha creado un conjunto muy completo de componentes que son lo que se usan para construir portadas en cualquier parte de sitio con cualquier propósito.
  • Los formularios de donación y suscripción se han desarrollado para integrarse en el sistema de landings con el objetivo de tener el mayor impacto y compromiso posible.
  • Drupal 8 se adapta a cualquier dispositivo. Pero en el desarrollo hemos ido más allá, trabajando estrechamente con KPMG, incluyendo herramientas en la propia gestión de contenidos que permiten definir diferentes puntos de ruptura dependiendo del dispositivo.
  • Hemos descubierto las posibilidades de CMI, el mecanismo que Drupal 8 incorpora para la gestión de despliegues. Con stbio.io y las herramientas utilizadas (Gitlab, Jenkis, Ansistrano) podemos hablar de que el devops en Drupal 8 es una realidad. En serio, que no os engañen, en PHP se puede hacer código de calidad con herramientas de calidad.
  • Uno de los objetivos en Unicef.es era conectar la gestión de contenidos con su unidad de negocio gestionada por su propio CRM. El equipo de 540, en su mejor estilo craftsmanship ha desarrollado una librería PHP independiente, que permite conectar Drupal con el CRM. Hemos comprobado que la potencia de esta parte del desarrollo es increíble.

En definitiva, la nueva Unicef.es está dando sus primeros pasos y nos alegra haber ayudado en ello. Es un gran proyecto con un gran propósito y de alguna manera esperamos que también pueda servir de inspiración.

Profiling en Drupal: Un caso práctico

Durante este verano hemos estado trabajando en la migración del portal del Museo Reina Sofía, en el que continuamente estamos aplicando mejoras, a un nuevo proveedor de hosting. El ecosistema hardware y software del museo se compone de una implantación bastante compleja de Drupal 7 como CMS y Apache Solr como indexador y buscador de contenidos.

A nivel de infraestructura hardware los diferentes portales del museo están desplegados en una infraestructura virtualizada en alta disponibilidad que incluye dos servidores frontales que incorporan Varnish como proxy inverso para cachear peticiones, apache con php5 como servidor de aplicaciones y memcache para el cacheo en memoria de Drupal. A nivel de base de datos disponemos de un cluster maestro-esclavo de Mysql en servidores separados que alojan también el servicio de búsquedas basado en Solr 4 en una implantación clusterizada.

El portal principal del Museo recibe bastante tráfico (incluido un rastreo continuo por parte de indexadores) que hace que cuidemos bastante el rendimiento del portal y su disponibilidad.

El problema

En el proceso de puesta en producción de la nueva infraestructura nos encontramos con un problema difícil de solucionar. Esporádicamente algunas páginas de edición de contenidos en el CMS tenían tiempos de renderizado de más de 20 segundos (llegando incluso a 40 segundos algunas de ellas), lo que dificultaba el trabajo de los editores de contenidos que continuamente están alimentando el portal.

El problema se podía demostrar fácilmente activando el módulo devel y configurándolo para que mostrase el tiempo de ejecución de página y las consultas a base de datos realizadas.

Una ejecución de una de las páginas en cuestión hacía aflorar el problema. Después de bastantes pruebas, identificamos que normalmente ocurría cuando el sistema tenía las caches de Drupal vacías (aunque ocurría esporádicamente también). La primera petición a una página de edición de un contenido devolvía tiempos de ejecución superiores a 20 segundos, la segunda petición ya daba tiempos normales (entre 1 o 2 segundos de ejecución total).

Después de verificar mil veces toda la configuración de los nuevos servidores, no encontrábamos el problema, además estábamos prácticamente seguros de que era un problema de configuración o potencia de los nuevos servidores, ya que en la infraestructura anterior el problema no ocurría nunca y podíamos compararlas en condiciones similares.

Primera tentativa de solución: ¡más hierro! Aunque habíamos verificado que los tiempos de ejecución de la capa de base de datos eran similares a los de la infraestructura anterior, no me resistía a pensar que el principal cuello de botella de Drupal era el responsable de todo esto, o sea, más potencia a la base de datos, más memoria a los frontales y más CPU a toda la infraestructura. ¿Mejora? ¡Ninguna! Además el log del módulo devel ya lo decía: tiempo de ejecución de llamadas a BD 3 segundos, tiempo de ejecución de página 30 segundos (en este caso la llamada a base de datos es muy lenta porque teníamos activado todo el debug ya para intentar localizar el problema).

Segundo intento: ¡simplificación! Estaba claro que teníamos algún bloqueo esporádico con algún recurso externo, lo primero en lo que pensé fue en alguna configuración errónea de memcache o apache solr de los que depende la infraestructura para muchas peticiones. Fuimos quitando uno a uno cada uno de estos servicios, pero el problema seguía ahí.

Tercer intento: ¡profiling! Teniendo en cuenta que esto solo lo reproducíamos en los servidores de producción y que estaban ya en activo, me resistía a meter una herramienta que afectase al servicio, pero visto que no encontrábamos el problema, nos decantamos por sacar uno de los frontales de nuestro balanceador y utilizar una herramienta de profiling para intentar localizar el problema. Vamos con los detalles.

Profiling al rescate

Para los que no lo sepáis, una herramienta de profiling permite analizar al detalle qué está ocurriendo con una petición a nivel de tiempos de ejecución y consumo de memoria de cada función por la que pasa la petición al servidor. Existen muchas herramientas de profiling, para este caso me decanté por usar la herramienta desarrollada por facebook: xhprof ya que su integración con Drupal 7 está muy documentada.

No me alargaré en la instalación de la herramienta y su integración con Drupal 7, es algo bastante sencillo de realizar con muchas referencias en internet (yo seguí este post). Una vez que todo está configurado (incluida la integración con el módulo devel de Drupal), cada petición al servidor mostrará un link en el pie de página que permite acceder al informe de profiling de dicha página.

Realmente lo difícil con xhprof es saber interpretar los resultados, así que intentaré aportar mi granito de arena con cómo he analizado los informes para dar con el problema, realmente estamos ante un caso sencillo pero muy común.

El informe de xhprof nada más abrirlo muestra 2 zonas:

  • Resumen de la petición: en este resumen podemos ver los grandes números de la petición analizada y nuestro problema. 19,6 segundos de ejecución de los cuales solo 2,5 son de consumo de CPU.
  • Principales funciones ejecutadas: en esta tabla se muestran las principales funciones ejecutadas con posibilidad de ordenarlas por diferentes criterios.

La forma de usar este informe consiste en trabajar sobre la ordenación de esta tabla de funciones, ya que cada columna representa un concepto diferente. Inicialmente la tabla viene ordenada por la columna “Included Wall Time”), que muestra el tiempo total de ejecución de cada función, incluido el tiempo de la propia función. Esta visualización normalmente no dice grandes cosas, al menos si buscamos funciones que estén consumiendo mucho tiempo de ejecución (como es mi caso). Lo único que vemos es que la función main ocupa el 100 % del tiempo de ejecución (ya que es la que engloba toda la petición de Drupal).

Realmente para detectar el problema, en este caso de alto consumo de tiempo de ejecución, ordenaremos la tabla por “Excl. Wall Time”, que muestra el tiempo de ejecución de una función excluyendo el tiempo de ejecución de las funciones hijas. Y ¡voilà! aquí esta el culpable:

En este informe tenemos un resultado concluyente, la función de php file_get_contents está ocupando 15 segundos de tiempo de ejecución, y se ejecuta 128 veces. Pero… y ahora ¿cómo encuentro yo cuál de las llamadas a esa función está dando problemas? (en nuestra implantación de Drupal 7 se usa más de 100 veces). Aquí esta lo bueno, podemos navegar por el informe para obtener más información sobre esta función pulsando sobre el nombre de la misma:

Ya empiezo a ver la luz, ahora sí tengo un culpable que puedo diseccionar. En esta visualización podemos observar que la función drupal_build_js_cache es la que está consumiendo todo el tiempo de ejecución. Y analizando el código de dicha función, vemos que es la que se encarga de “empaquetar” todos los ficheros JS de la aplicación y generar un fichero con el agregado para optimizar el rendimiento del frontend. Y como el problema está en la llamada a file_get_contents de dicho fichero, parece que tenemos un problema con alguna lectura de alguno de esos ficheros en el servidor. ¿Pero cuál?, ¿será tema de permisos?, ¿será que el acceso a disco en los nuevos servidores es superlento? Bueno, no queda otra que debugear esta función, el problema es que como solo nos pasa en producción no podemos meter un debugger interactivo como xdebug, así que nos tendremos que servir de un simple log como este:

Y revisando el log generado por una petición que ha presentado el problema vemos lo siguiente:

¡2 ficheros JS que se están intentando empaquetar provienen no de un fichero local, sino de una llamada http!. En este caso la llamada http va contra nuestra propia máquina en un subdominio donde estamos sirviendo los ficheros estáticos para optimizar el rendimiento del frontend. ¿Y cuál es el problema? Este:

Resulta que los propios servidores no son capaces de acceder por http a sí mismos. Esto es lo que provoca el bloqueo y los tiempos de espera hasta que la función file_get_contents da un timeout.

La solución

Que los servidores resuelvan esa petición. Lección aprendida después de dedicar multitud de horas y recursos a intentar revisar el tunning del servidor, un profiling puede dar pistas de un problema puntual de rendimiento y ahorrar muchos dolores de cabeza como los que he tenido el último mes.

¡Gracias, xhprof!

Profiling en Drupal: Un caso práctico

Durante este verano hemos estado trabajando en la migración del portal del Museo Reina Sofía, en el que continuamente estamos aplicando mejoras, a un nuevo proveedor de hosting. El ecosistema hardware y software del museo se compone de una implantación bastante compleja de Drupal 7 como CMS y Apache Solr como indexador y buscador de contenidos.

A nivel de infraestructura hardware los diferentes portales del museo están desplegados en una infraestructura virtualizada en alta disponibilidad que incluye dos servidores frontales que incorporan Varnish como proxy inverso para cachear peticiones, apache con php5 como servidor de aplicaciones y memcache para el cacheo en memoria de Drupal. A nivel de base de datos disponemos de un cluster maestro-esclavo de Mysql en servidores separados que alojan también el servicio de búsquedas basado en Solr 4 en una implantación clusterizada.

El portal principal del Museo recibe bastante tráfico (incluido un rastreo continuo por parte de indexadores) que hace que cuidemos bastante el rendimiento del portal y su disponibilidad.

El problema

En el proceso de puesta en producción de la nueva infraestructura nos encontramos con un problema difícil de solucionar. Esporádicamente algunas páginas de edición de contenidos en el CMS tenían tiempos de renderizado de más de 20 segundos (llegando incluso a 40 segundos algunas de ellas), lo que dificultaba el trabajo de los editores de contenidos que continuamente están alimentando el portal.

El problema se podía demostrar fácilmente activando el módulo devel y configurándolo para que mostrase el tiempo de ejecución de página y las consultas a base de datos realizadas.

Una ejecución de una de las páginas en cuestión hacía aflorar el problema. Después de bastantes pruebas, identificamos que normalmente ocurría cuando el sistema tenía las caches de Drupal vacías (aunque ocurría esporádicamente también). La primera petición a una página de edición de un contenido devolvía tiempos de ejecución superiores a 20 segundos, la segunda petición ya daba tiempos normales (entre 1 o 2 segundos de ejecución total).

Después de verificar mil veces toda la configuración de los nuevos servidores, no encontrábamos el problema, además estábamos prácticamente seguros de que era un problema de configuración o potencia de los nuevos servidores, ya que en la infraestructura anterior el problema no ocurría nunca y podíamos compararlas en condiciones similares.

Primera tentativa de solución: ¡más hierro! Aunque habíamos verificado que los tiempos de ejecución de la capa de base de datos eran similares a los de la infraestructura anterior, no me resistía a pensar que el principal cuello de botella de Drupal era el responsable de todo esto, o sea, más potencia a la base de datos, más memoria a los frontales y más CPU a toda la infraestructura. ¿Mejora? ¡Ninguna! Además el log del módulo devel ya lo decía: tiempo de ejecución de llamadas a BD 3 segundos, tiempo de ejecución de página 30 segundos (en este caso la llamada a base de datos es muy lenta porque teníamos activado todo el debug ya para intentar localizar el problema).

Segundo intento: ¡simplificación! Estaba claro que teníamos algún bloqueo esporádico con algún recurso externo, lo primero en lo que pensé fue en alguna configuración errónea de memcache o apache solr de los que depende la infraestructura para muchas peticiones. Fuimos quitando uno a uno cada uno de estos servicios, pero el problema seguía ahí.

Tercer intento: ¡profiling! Teniendo en cuenta que esto solo lo reproducíamos en los servidores de producción y que estaban ya en activo, me resistía a meter una herramienta que afectase al servicio, pero visto que no encontrábamos el problema, nos decantamos por sacar uno de los frontales de nuestro balanceador y utilizar una herramienta de profiling para intentar localizar el problema. Vamos con los detalles.

Profiling al rescate

Para los que no lo sepáis, una herramienta de profiling permite analizar al detalle qué está ocurriendo con una petición a nivel de tiempos de ejecución y consumo de memoria de cada función por la que pasa la petición al servidor. Existen muchas herramientas de profiling, para este caso me decanté por usar la herramienta desarrollada por facebook: xhprof ya que su integración con Drupal 7 está muy documentada.

No me alargaré en la instalación de la herramienta y su integración con Drupal 7, es algo bastante sencillo de realizar con muchas referencias en internet (yo seguí este post). Una vez que todo está configurado (incluida la integración con el módulo devel de Drupal), cada petición al servidor mostrará un link en el pie de página que permite acceder al informe de profiling de dicha página.

Realmente lo difícil con xhprof es saber interpretar los resultados, así que intentaré aportar mi granito de arena con cómo he analizado los informes para dar con el problema, realmente estamos ante un caso sencillo pero muy común.

El informe de xhprof nada más abrirlo muestra 2 zonas:

  • Resumen de la petición: en este resumen podemos ver los grandes números de la petición analizada y nuestro problema. 19,6 segundos de ejecución de los cuales solo 2,5 son de consumo de CPU.
  • Principales funciones ejecutadas: en esta tabla se muestran las principales funciones ejecutadas con posibilidad de ordenarlas por diferentes criterios.

La forma de usar este informe consiste en trabajar sobre la ordenación de esta tabla de funciones, ya que cada columna representa un concepto diferente. Inicialmente la tabla viene ordenada por la columna “Included Wall Time”), que muestra el tiempo total de ejecución de cada función, incluido el tiempo de la propia función. Esta visualización normalmente no dice grandes cosas, al menos si buscamos funciones que estén consumiendo mucho tiempo de ejecución (como es mi caso). Lo único que vemos es que la función main ocupa el 100 % del tiempo de ejecución (ya que es la que engloba toda la petición de Drupal).

Realmente para detectar el problema, en este caso de alto consumo de tiempo de ejecución, ordenaremos la tabla por “Excl. Wall Time”, que muestra el tiempo de ejecución de una función excluyendo el tiempo de ejecución de las funciones hijas. Y ¡voilà! aquí esta el culpable:

En este informe tenemos un resultado concluyente, la función de php file_get_contents está ocupando 15 segundos de tiempo de ejecución, y se ejecuta 128 veces. Pero… y ahora ¿cómo encuentro yo cuál de las llamadas a esa función está dando problemas? (en nuestra implantación de Drupal 7 se usa más de 100 veces). Aquí esta lo bueno, podemos navegar por el informe para obtener más información sobre esta función pulsando sobre el nombre de la misma:

Ya empiezo a ver la luz, ahora sí tengo un culpable que puedo diseccionar. En esta visualización podemos observar que la función drupal_build_js_cache es la que está consumiendo todo el tiempo de ejecución. Y analizando el código de dicha función, vemos que es la que se encarga de “empaquetar” todos los ficheros JS de la aplicación y generar un fichero con el agregado para optimizar el rendimiento del frontend. Y como el problema está en la llamada a file_get_contents de dicho fichero, parece que tenemos un problema con alguna lectura de alguno de esos ficheros en el servidor. ¿Pero cuál?, ¿será tema de permisos?, ¿será que el acceso a disco en los nuevos servidores es superlento? Bueno, no queda otra que debugear esta función, el problema es que como solo nos pasa en producción no podemos meter un debugger interactivo como xdebug, así que nos tendremos que servir de un simple log como este:

Y revisando el log generado por una petición que ha presentado el problema vemos lo siguiente:

¡2 ficheros JS que se están intentando empaquetar provienen no de un fichero local, sino de una llamada http!. En este caso la llamada http va contra nuestra propia máquina en un subdominio donde estamos sirviendo los ficheros estáticos para optimizar el rendimiento del frontend. ¿Y cuál es el problema? Este:

Resulta que los propios servidores no son capaces de acceder por http a sí mismos. Esto es lo que provoca el bloqueo y los tiempos de espera hasta que la función file_get_contents da un timeout.

La solución

Que los servidores resuelvan esa petición. Lección aprendida después de dedicar multitud de horas y recursos a intentar revisar el tunning del servidor, un profiling puede dar pistas de un problema puntual de rendimiento y ahorrar muchos dolores de cabeza como los que he tenido el último mes.

¡Gracias, xhprof!

Cinco sesiones destacadas de la Drupalcon Dublín 2016

Un año más y gracias a la organización de la DrupalCon, he podido asistir a este fantástico evento que se celebró en Dublín.

Son días que pasan muy rápido porque son muy ajetreados: saludar a los amigos, asistir a sesiones, ayudar a otros mentorizando… Si cabe destacar algo, siempre digo lo mismo, es poder encontrarte con esos amigos con los que estás casi a diario colaborando y contribuyendo. Además, un año más me ofrecí como mentor para ayudar a otra gente a que se inicie a contribuir en el Core de Drupal. Siempre es un placer poder ayudar a otros

De todo lo que se habló en la DrupalCon, resalto cinco sesiones que me han parecido especialmente interesantes.

Destacaría como siempre la sesión de Morten sobre 21 things I learned with Twig & Drupal, una sesión con 260 slides contadas en 60 minutos. Rápido y directo, donde muestra multitud de ejemplos de los que aprender.

Una de las iniciativas más interesantes es la de e0ipso (Mateu) y Prestonso sobre la API First Initiative y la sesión de Mateu de Advanced Web Services with JSON API. Tuve la suerte de poder ver junto a Mateu el proceso y características de JSON API y algunas de las issue en las que estuve trabajando junto a él. Os dejo el vídeo de su sesión:

En cuanto a escalabilidad y rendimiento de entornos en Drupal la sesión de Fabianx de 4x High Performance for Drupal – Step by Step – The ultimate beginner’s guide me resultó muy clarificadora sobre qué cosas son necesarias tener en cuenta.

Una de las novedades en las que se trabaja es en LCache para futuras releases Faster and More Scalable than Memcache/Redis: Tiered Storage with LCache. No pude asistir a esa sesión, pero me resultó interesante conocer que existen novedades al respecto.
Os dejo el vídeo:

Por último, en cuanto a calidad de código y testear el código, comentaría la sesión de klausi y dawehner sobre Automated Testing: PHPUnit all the way en la que aparte de mostrarnos lo que existe actualmente, nos mostraron también las novedades que se van a incorporar en las futuras versiones.

Y sobre todo, lo mejor, encontrarte con los amigos drupaleros y contribuir al proyecto Drupal.

Cinco sesiones destacadas de la Drupalcon Dublín 2016

Un año más y gracias a la organización de la DrupalCon, he podido asistir a este fantástico evento que se celebró en Dublín.

Son días que pasan muy rápido porque son muy ajetreados: saludar a los amigos, asistir a sesiones, ayudar a otros mentorizando… Si cabe destacar algo, siempre digo lo mismo, es poder encontrarte con esos amigos con los que estás casi a diario colaborando y contribuyendo. Además, un año más me ofrecí como mentor para ayudar a otra gente a que se inicie a contribuir en el Core de Drupal. Siempre es un placer poder ayudar a otros

De todo lo que se habló en la DrupalCon, resalto cinco sesiones que me han parecido especialmente interesantes.

Destacaría como siempre la sesión de Morten sobre 21 things I learned with Twig & Drupal, una sesión con 260 slides contadas en 60 minutos. Rápido y directo, donde muestra multitud de ejemplos de los que aprender.

Una de las iniciativas más interesantes es la de e0ipso (Mateu) y Prestonso sobre la API First Initiative y la sesión de Mateu de Advanced Web Services with JSON API. Tuve la suerte de poder ver junto a Mateu el proceso y características de JSON API y algunas de las issue en las que estuve trabajando junto a él. Os dejo el vídeo de su sesión:

En cuanto a escalabilidad y rendimiento de entornos en Drupal la sesión de Fabianx de 4x High Performance for Drupal – Step by Step – The ultimate beginner’s guide me resultó muy clarificadora sobre qué cosas son necesarias tener en cuenta.

Una de las novedades en las que se trabaja es en LCache para futuras releases Faster and More Scalable than Memcache/Redis: Tiered Storage with LCache. No pude asistir a esa sesión, pero me resultó interesante conocer que existen novedades al respecto.
Os dejo el vídeo:

Por último, en cuanto a calidad de código y testear el código, comentaría la sesión de klausi y dawehner sobre Automated Testing: PHPUnit all the way en la que aparte de mostrarnos lo que existe actualmente, nos mostraron también las novedades que se van a incorporar en las futuras versiones.

Y sobre todo, lo mejor, encontrarte con los amigos drupaleros y contribuir al proyecto Drupal.