Hace 10 años, Google se enfrentaba a un cuello de botella crítico causado por tiempos de compilación de C++ extremadamente prolongados y necesitaba una forma totalmente nueva de resolverlo. Los ingenieros de Google abordaron el reto creando un nuevo lenguaje llamado Go (también conocido como Golang). El nuevo lenguaje de Go toma prestadas las mejores partes de C++, (sobre todo sus características de rendimiento y seguridad) y las combina con la velocidad de Python para permitir que Go utilice rápidamente múltiples núcleos y sea capaz de implementar la concurrencia.

Aquí, en Coralogix, estamos analizando los registros de nuestros clientes con el fin de darles información en tiempo real, alertas y metadatos sobre sus registros. Para ello, la fase de parsing, que es muy compleja y está cargada de toneladas de reglas para cada servicio de línea de logs, debe ser extremadamente rápida. Esa es una de las razones por las que decidimos utilizar Go lang.

El nuevo servicio está funcionando a tiempo completo en producción y, aunque estamos viendo grandes resultados, necesita ejecutarse en máquinas de alto rendimiento. Más de decenas de miles de millones de registros son analizados cada día por este servicio Go que se ejecuta en una instancia AWS m4.2xlarge con 8 CPUs y 36 GB de memoria.

En esta etapa, podríamos haber dado por terminado el día sintiéndonos muy bien de que todo estaba funcionando bien, pero no es así como rodamos aquí en Coralogix. Queríamos más funciones (rendimiento, etc) utilizando menos (instancias de AWS). Para mejorar, primero necesitábamos entender la naturaleza de nuestros cuellos de botella y cómo podemos reducirlos o eliminarlos por completo.

Decidimos ejecutar algunos perfiles de Golang en nuestro servicio y comprobar qué causaba exactamente el alto consumo de CPU para ver si podemos optimizar.

En primer lugar, hemos actualizado a la última versión estable de Go (una parte clave del ciclo de vida del software). Estábamos en la versión Go v1.12.4, y la última era la 1.13.8. La versión 1.13, según la documentación, tenía importantes mejoras en la biblioteca de tiempo de ejecución y algunos otros componentes que utilizaban principalmente el uso de la memoria. En resumen, trabajar con la última versión estable fue útil y nos ahorró bastante trabajo →

Así, el consumo de memoria mejoró de unos ~800MB a ~180MB.

En segundo lugar, con el fin de obtener una mejor comprensión de nuestro proceso y entender dónde estamos gastando tiempo y recursos, empezamos a perfilar.

Perfilar diferentes servicios y lenguajes de programación puede parecer complejo e intimidante, pero en realidad es bastante fácil en Go y se puede describir en pocos comandos. Go tiene una herramienta dedicada llamada ‘pprof’ que debe ser habilitada en su aplicación escuchando una ruta (puerto por defecto- 6060) y utilizar el paquete Go para la gestión de las conexiones http:

import _ "net/http/pprof"

Entonces inicialice lo siguiente en su función principal o bajo su paquete de ruta:

go func() {log.Println(http.ListenAndServe("localhost:6060", nil))}()

Ahora puede iniciar su servicio y conectarse a

http://localhost:6060/debug/pprof

La documentación completa de Go se puede encontrar aquí.

El perfil por defecto para pprof será un muestreo de 30 segundos del uso de la CPU. Hay algunos caminos diferentes que permiten el muestreo para el uso de la CPU, el uso de la pila y más.

Nos centramos en nuestro uso de la CPU, así que tomamos un perfil de 30 segundos en producción y descubrimos lo que se ve en la imagen de abajo (recordatorio: esto es después de actualizar nuestra versión de Go y disminuir las partes internas de Go al mínimo):

Perfil de Go – Coralogix

Como puedes ver, encontramos mucha actividad de paquetes en tiempo de ejecución, lo que indicaba específicamente actividad de GC → Casi el 29% de nuestra CPU (sólo los 20 objetos más consumidos) es utilizado por GC. Dado que el GC de Go es bastante rápido y está bastante optimizado, la mejor práctica es no cambiarlo o modificarlo, y dado que nuestro consumo de memoria era muy bajo (en comparación con nuestra versión anterior de Go) el principal sospechoso era una alta tasa de asignación de objetos.

Si ese es el caso, hay dos cosas que podemos hacer:

  • Ajustar la actividad del GC de Go para que se adapte al comportamiento de nuestro servicio, lo que significa – retrasar su activación para activar el GC con menos frecuencia. Esto nos obligará a compensar con más memoria.
  • Encontrar la función, área o línea de nuestro código que asigna demasiados objetos.

Mirando nuestro tipo de instancia, estaba claro que nos sobraba mucha memoria y que actualmente estamos limitados por la CPU de la máquina. Así que simplemente cambiamos esa proporción. Golang, desde sus primeros días, tiene una bandera que la mayoría de los desarrolladores no conocen, llamada GOGC. Esta bandera, con un valor por defecto de 100, simplemente le dice al sistema cuando disparar la GC. El valor por defecto activará el proceso de GC siempre que la pila alcance el 100% de su tamaño inicial. Si se cambia este valor a un número más alto, se retrasará la activación de la GC y si se reduce, se activará antes. Empezamos a comparar diferentes valores y el mejor rendimiento para nuestro propósito se logró cuando se utilizó: GOGC=2000.

Esto incrementó inmediatamente nuestro uso de memoria de ~200MB a ~2.7GB (Eso es después de que el consumo de memoria disminuyera debido a nuestra actualización de la versión Go) y disminuyó nuestro uso de CPU en ~10%.
La siguiente captura de pantalla muestra los resultados del benchmark:

GOGC =2000 resultados – Coralogix benchmark

Las 4 funciones que más CPU consumen son las de nuestro servicio, lo cual tiene sentido. El uso total de GC es ahora ~13%, menos de la mitad de su consumo anterior(!)

Podríamos haber parado ahí, pero decidimos descubrir dónde y por qué asignamos tantos objetos. Muchas veces, hay una buena razón para ello (por ejemplo en el caso del procesamiento de flujos donde creamos muchos objetos nuevos por cada mensaje que recibimos y necesitamos deshacernos de ellos porque son irrelevantes para el siguiente mensaje), pero hay casos en los que hay una forma fácil de optimizar y disminuir drásticamente la creación de objetos.

Para empezar, vamos a ejecutar el mismo comando que antes con un pequeño cambio para tomar el volcado del heap:

http://localhost:6060/debug/pprof/heap

Para consultar el fichero de resultados puedes ejecutar el siguiente comando dentro de tu carpeta de código para analizar el volcado:

go tool pprof -alloc_objects <HEAP.PROFILE.FILE>

Nuestra instantánea tenía el siguiente aspecto:

Todo parecía razonable excepto la tercera fila, que es una función de monitorización que informa a nuestro exportador prometheus al final de cada fase de análisis de reglas de Coralogix. Para profundizar, ejecutamos el siguiente comando:

list <FunctionName>

Por ejemplo:

list reportRuleExecution

Y obtuvimos lo siguiente:

Dejar un comentario

Tu dirección de correo electrónico no será publicada.