Cómo instrumentar una aplicación de microservicios políglota con Elastic APM

Elastic Stack y Elastic APM ofrecen observabilidad para soluciones modernas basadas en microservicios, así como para aplicaciones monolíticas.

El (APM) Application Performance Monitoring combina diferentes tecnologías para proporcionar una visión profunda, transparente y holística de lo que hace cada componente de la aplicación, dónde, cuándo y para cuánto tiempo. Nos muestra cómo interactúan los servicios entre sí, y nos permite destapar los cuellos de botella. Estos análisis exhaustivos ayudan a detectar, debug y solucionar problemas más rápido, lo que resulta en una mejor experiencia del usuario y en una eficiencia empresarial aumentada.

Como beneficio adicional, los datos APM almacenados en Elasticsearch son un índice más. Así que la combinación y correlación de las métricas de la aplicación con otros datos operativos se convierte en algo viable y accesible.

Las herramientas de observabilidad y APM pueden actuar como catalizadores culturales de lo que llamamos Devops, para organizaciones de todos tipos y tamaños. Permite conectar los equipos de desarrollo con los de operaciones, seguridad, productos, etc. Dado que todos equipos procuran aumentar su comprensión de los sistemas y aplicaciones y mejorar su rendimiento y fiabilidad, APM es una de las herramientas que les puede ayudar a remar en la misma dirección.

En este blog, vamos a usar una aplicación de ejemplo para demostrar cómo se puede instrumentar una aplicación de microservicios usando Elastic APM. El planteamiento da énfasis al Distributed Tracing, es decir, a la implementación de trazas que cubren todos los servicios involucrados en cada solicitud.

La aplicación de ejemplo que vamos a usar fue creada para "evaluar varios instrumentos de monitoreo, rastreo, etc". Aunque es una aplicación bastante básica, va más allá de los ejemplos de "hello world". Para realizar este blog, el proyecto original se bifurcó, se aplicaron algunas modificaciones y actualizaciones, y se instrumentó con Elastic APM.

Es una aplicación de gestión de tareas, y aquí se puede ver una vista de alto nivel de la arquitectura:

Evidentemente, existe más de una forma de configurar los agentes e instrumentar una aplicación con Elastic APM. Lo que se presenta a continuación es solo una opción entre muchas: no pretende ser la única forma de configurar las cosas, sino demostrar la flexibilidad que nos proporciona una solución de observabilidad como la de Elastic.

Descripción general

La aplicación está compuesta por los siguiente cinco servicios:

• frontend implementado en vue.js para la capa de presentación
• auth-api está escrita en Go y proporciona la funcionalidad de autenticación
• todo-api está escrita con NodeJS utilizando el “Express” framework. Proporciona la funcionalidad CRUD para los registros de tareas. Además, registra las operaciones de "creación" y "eliminación" en una cola de Redis, para que luego puedan ser procesadas por Log Message Processor
• users-api es un proyecto Spring Boot escrito en Java y proporciona la funcionalidad relacionada con los perfiles de cada usuario
• log Message Processor es un procesador de colas de mensajes, escrito en Python, que simplemente lee los mensajes de la cola de Redis y después los imprime en “stdout”

Así que, en total, la aplicación está compuesta de 6 contenedores:

docker ps
CONTAINER ID        IMAGE                   COMMAND                  CREATED             STATUS              PORTS                    NAMES
6696f65b1759        frontend                "docker-entrypoint.s..."   6 hours ago         Up 58 seconds       0.0.0.0:8080->8080/tcp   microservice-app-example_frontend_1
6cc8a27f10f5        todos-api               "docker-entrypoint.s..."   6 hours ago         Up 58 seconds       8082/tcp                 microservice-app-example_todos-api_1
3e471f2163ca        log-message-processor   "python3 -u main.py"       6 hours ago         Up 58 seconds                                microservice-app-example_log-message-processor_1
bc1f09716288        auth-api                "/bin/sh -c /go/src/..."   6 hours ago         Up 58 seconds       8081/tcp                 microservice-app-example_auth-api_1
7144abac0d7c        users-api               "java -jar ./target/..."   6 hours ago         Up 59 seconds       8083/tcp                 microservice-app-example_users-api_1
84416563c37f        redis                   "docker-entrypoint.s..."   6 hours ago         Up 59 seconds       6379/tcp                 microservice-app-example_redis-queue_1

Cómo configurar y ejecutar el laboratorio

Requisitos previos

La demo utiliza Elastic Stack con APM en ESS. Si aún no tienes una cuenta de servicio Elasticsearch se puede configurar una prueba gratuita de una manera sencilla y segura. Cuando se arranca un cluster de Elasticsearch, viene con una instalación de Kibana y un servidor APM incluidos por defecto.

Esta demo se realizó y se probó en las versiones del stack 7.5.0 y 7.6.1.

Aquí se puede ver una vista de las instancias del clúster de prueba que se utilizó.

La aplicación se construye y ejecuta usando docker-compose, por lo que es necesario tenerlo instalado en la máquina local.

Con respecto a los agentes instalados, en la fase de la creación de los contenedores para cada microservicio se instalará la última versión disponible de cada uno,.

Configuración

Para que la aplicación se ejecute en nuestra máquina local y se configure para enviar datos APM al clúster de Elasticsearch Service, hacen falta los siguientes pasos:

Clonar el proyecto:

git clone https://github.com/nephel/microservice-app-example.git

Crear un archivo llamado .env en el directorio raíz del proyecto con el token y el servidor APM, para que la aplicación sepa donde hay que enviar los datos relacionados con APM.

cd microservice-app-example

vi .env

TOKEN=XXXX
SERVER=XXXX

Los valores se pueden obtener en esta página de la Consola de administración de Elastic Cloud.

Esos valores se pasarán como variables de entorno en cada contenedor, como se puede ver en el archivo docker-compose.yaml

ELASTIC_APM_SECRET_TOKEN: "${TOKEN}"
ELASTIC_APM_SERVER_URL: "${SERVER}"

Arrancando la aplicación

Para arrancar la aplicación del proyecto clonado, se debe ejecutar docker-compose up --build en el directorio raíz del proyecto. Esto creará todos los contenedores y sus dependencias, y comenzará a enviar datos de trazas de la aplicación al servidor APM.

La primera vez que se construye con docker-compose la aplicación con todos sus microservicios y sus dependencias, tardará un poco.

La configuración para APM y los microservicios, está en modo DEBUG o verboso. Esto es intencional, ya que es útil al configurar y probar. Se puede cambiar fácilmente en el archivo docker-compose.yaml si resulta demasiado detallado.

En la configuración del servidor APM en Elastic Cloud, debemos habilitar RUM con apm-server.rum.enabled: true en los User setting overrides, como se puede ver aquí:

Para generar datos de APM necesitamos usar a la aplicación y generar algo de tráfico y solicitudes.

Una vez que la aplicación ha arrancado, estará disponible en esta URL http://127.0.0.1:8080 Hay que tener en cuenta que el nombre de usuario / contraseñas son por defecto:

• admin / admin
• johnd / foo
• janed / ddd

Los usaremos al hacer el login para añadir algunas tareas y eliminar otras, y repetiremos con los distintos usuarios.

En este breve vídeo se puede ver cómo arrancar la aplicación con docker-compose, cómo usar la aplicación y cómo navegar la interfaz del usuario de APM dentro de Kibana.

Los microservicios y su instrumentación

Aquí se puede ver una vista de los cinco servicios tal como aparecen en la interfaz de usuario de APM:

Cada servicio aparece en la lista, con información de alto nivel sobre sus transacciones, su entorno y su idioma. A continuación, vamos a ver cómo se instrumentó cada microservicio y qué se puede ver en la interfaz usuario de APM en Kibana para cada uno.

Frontend Vue.js

La tecnología utilizada para el frontend es https://vuejs.org/ la cual es compatible con el agente de Elastic Real User Monitoring (RUM), es decir, se puede auto-instrumentar este parte de la aplicación, con tan sólo añadir unas líneas de código.

El paquete @elastic/apm-rum-vue se instala a través de npm, en el fichero frontend/Dockerfile, con las siguientes líneas de código:

COPY package.json ./
RUN npm install
RUN npm install --save @elastic/apm-rum-vue
COPY . .
CMD ["sh", "-c", "npm start" ]

Su configuración se puede ver en este fichero frontend/src/router/index.js:

...
import { ApmVuePlugin } from '@elastic/apm-rum-vue'
Vue.use(Router)
const router = new Router({
  mode: 'history',
  routes: [
    {
      path: '/login',
      name: 'login',
      component: require('@/components/Login.vue')
    },
    {
      path: '/',
      alias: '/todos',
      name: 'todos',
      component: require('@/components/Todos.vue'),
      beforeEnter: requireLoggedIn
    }
  ]
})
const ELASTIC_APM_SERVER_URL = process.env.ELASTIC_APM_SERVER_URL
Vue.use(ApmVuePlugin, {
  router,
  config: {
    serviceName: 'frontend',
    serverUrl: ELASTIC_APM_SERVER_URL,
    serviceVersion: '',
    logLevel: 'debug'
  }
})
...
...
export default router

Además de los tramos (spans) que se han añadido a través de la auto-instrumentación, también se pueden agregar tramos personalizados y específicos para los varios componentes, por ejemplo, en el fichero frontend/src/components/Login.vue, añadimos lo siguiente:

...
      span: null
    }
  },
  created () {
    this.span = this.$apm.startSpan('component-login', 'custom')
  },
  mounted () {
    this.span && this.span.end()
  }
...

Se capturan tanto los eventos de tipo page load como los de tipo route-change. Son transacciones y su nombre viene de la URL de la ruta de cada petición.

Esta es una vista de las transacciones que vemos para el servicio frontend. Podemos observar que el menú desplegable nos permite filtrar por tipo de transacción:

En cualquier momento se puede crear en un evento de tipo “page-load” y su transacción, recargando la página eliminando la caché (por ejemplo, command-shift-R en un mac).

Los datos de APM están almacenados en Elasticsearch como índices. Utilizando “Discover” esta sería la vista de los índices “apm-*”, filtrado para transacciones de tipo page load:

Auth API Go Echo

Este microservicio ha sido implementado en Golang utilizando el framework echo, versión 3, lo cual también es compatible con el agente de Elastic APM.

La instrumentación se realiza principalmente en el fichero auth-api/main.go, donde se importan el agente de elastic APM junto con los dos módulos apmecho y apmhttp:

...
        "go.elastic.co/apm"
        "go.elastic.co/apm/module/apmecho"
        "go.elastic.co/apm/module/apmhttp"
        "github.com/labstack/echo/middleware"
...

La auto-instrumentación para el middleware de “echo” se realiza en la línea 48:

...
 28 func main() {
 29         hostport := ":" + os.Getenv("AUTH_API_PORT")
 30         userAPIAddress := os.Getenv("USERS_API_ADDRESS")
 31
 32         envJwtSecret := os.Getenv("JWT_SECRET")
 33         if len(envJwtSecret) != 0 {
 34                 jwtSecret = envJwtSecret
 35         }
 36
 37         userService := UserService{
 38                 Client:         apmhttp.WrapClient(http.DefaultClient),
 39                 UserAPIAddress: userAPIAddress,
 40                 AllowedUserHashes: map[string]interface{}{
 41                         "admin_admin": nil,
 42                         "johnd_foo":   nil,
 43                         "janed_ddd":   nil,
 44                 },
 45         }
 46
 47         e := echo.New()
 48         e.Use(apmecho.Middleware())
 49
 50         e.Use(middleware.Logger())
 51         e.Use(middleware.Recover())
 52         e.Use(middleware.CORS())
 53
 54         // Route => handler
 55         e.GET("/version", func(c echo.Context) error {
 56                 return c.String(http.StatusOK, "Auth API, written in Go\n")
 57         })
 58
 59         e.POST("/login", getLoginHandler(userService)
...

Como se puede ver en el fichero auth-api/user.go, el microservicio lanza solicitudes HTTP al microservicio users-api.

La envoltura del cliente HTTP se realiza en la línea 38, rastreando la solicitud lanzada de un microservicio al otro, realizando así el rastreo distribuido.

Para la explicación de esta implementación, se puede encontrar más información en este blog y en esta parte de la documentación:

Rastreo de solicitudes HTTP salientes
Para rastrear una solicitud HTTP saliente, se debe instrumentar el cliente HTTP y asegurarse de que el contexto de la solicitud de inclusión se propague a la solicitud saliente. El cliente instrumentado usará esto para crear un intervalo y también para inyectar encabezados en la solicitud HTTP saliente. Echemos un vistazo a cómo se ve en la práctica:
...
Si esta solicitud saliente es manejada por otra aplicación equipada con Elastic APM, terminará con un "rastreo distribuido" - un rastreo (colección de transacciones y tramos relacionados) que cruza servicios. El cliente instrumentado inyectará un encabezado que identifica el intervalo para la solicitud HTTP saliente, y el servicio receptor extraerá ese encabezado y lo usará para correlacionar el intervalo del cliente con la transacción que registra intervalos.

Además, se agregaron tramas personalizadas utilizando el API de span como se puede ver en el fichero main.go:

...
func getLoginHandler(userService UserService) echo.HandlerFunc {
        f := func(c echo.Context) error {
                span, _ := apm.StartSpan(c.Request().Context(), "request-login", "app")
                requestData := LoginRequest{}
                decoder := json.NewDecoder(c.Request().Body)
                if err := decoder.Decode(&requestData); err != nil {
                        log.Printf("could not read credentials from POST body: %s", err.Error())
                        return ErrHttpGenericMessage
                }
                span.End()
                span, ctx := apm.StartSpan(c.Request().Context(), "login", "app")
                user, err := userService.Login(ctx, requestData.Username, requestData.Password)
                if err != nil {
                        if err != ErrWrongCredentials {
                                log.Printf("could not authorize user '%s': %s", requestData.Username, err.Error())
                                return ErrHttpGenericMessage
                        }
                        return ErrWrongCredentials
                }
                token := jwt.New(jwt.SigningMethodHS256)
                span.End()
                // Set claims
                span, _ = apm.StartSpan(c.Request().Context(), "generate-send-token", "custom")
                claims := token.Claims.(jwt.MapClaims)
                claims["username"] = user.Username
                claims["firstname"] = user.FirstName
                claims["lastname"] = user.LastName
                claims["role"] = user.Role
                claims["exp"] = time.Now().Add(time.Hour * 72).Unix()
                // Generate encoded token and send it as response.
                t, err := token.SignedString([]byte(jwtSecret))
                if err != nil {
                        log.Printf("could not generate a JWT token: %s", err.Error())
                        return ErrHttpGenericMessage
                }
                span.End()

Users-api Java

El servicio utiliza Spring Boot, que también es compatible con el agente Java. Es muy fácil auto-instrumentar Spring Boot.

El agente se instala utilizando la "configuración del API programática para auto adjuntar". En este fichero: users-api/src/main/java/com/elgris/usersapi/UsersApiApplication.java

Se hace la importación:

...
import co.elastic.apm.attach.ElasticApmAttacher;
@SpringBootApplication
public class UsersApiApplication {
        public static void main(String[] args) {
                ElasticApmAttacher.attach();
                SpringApplication.run(UsersApiApplication.class, args);
        }
}
...

Y en el fichero, users-api pom.xml, se agregó lo siguiente, para la instalación del agente:

                <dependency>
                        <groupId>co.elastic.apm</groupId>
                        <artifactId>apm-agent-attach</artifactId>
                        <version>[1.14.0,)</version>
               </dependency>

A continuación se muestra un ejemplo de rastreo distribuido. La traza está compuesta por las transacciones y tramas que se están creando cuando la solicitud fluye a través de los microservicios, desde el formulario frontend, hasta la solicitud POST a la “auth-API” para la autenticación, que a su vez realiza una solicitud GET a la “users-API” para la recuperación del perfil de usuario.

Todos-api Node.js

El servicio "todo" utiliza el framerork Express, que también se puede auto-instrumentar con el agente de Elastic para Node.js.

El agente se instala agregando esta línea al Dockerfile:

RUN npm install elastic-apm-node --save

Para inicializar el agente, se agrega lo siguiente en todos-api/server.js

...
const apm = require('elastic-apm-node').start({
  // Override service name from package.json
  // Allowed characters: a-z, A-Z, 0-9, -, _, and space
  serviceName: 'todos-api',
  // Use if APM Server requires a token
  secretToken: process.env.ELASTIC_APM_SECRET_TOKEN,
  // Set custom APM Server URL (default: http://localhost:8200)
  serverUrl: process.env.ELASTIC_APM_SERVER_URL,
})
....

Además de la auto-instrumentación, se añaden tramas personalizadas en el fichero todos-api/todoController.js para las acciones de la aplicación como la de creación y eliminación de las tareas:

...
    create (req, res) {
        // TODO: must be transactional and protected for concurrent access, but
        // the purpose of the whole example app it's enough
        const span = apm.startSpan('creating-item')
        const data = this._getTodoData(req.user.username)
        const todo = {
            content: req.body.content,
            id: data.lastInsertedID
        }
        data.items[data.lastInsertedID] = todo
        data.lastInsertedID++
        this._setTodoData(req.user.username, data)
        if (span) span.end()
        this._logOperation(OPERATION_CREATE, req.user.username, todo.id)
        res.json(todo)
    }
    delete (req, res) {
        const data = this._getTodoData(req.user.username)
        const id = req.params.taskId
        const span = apm.startSpan('deleting-item')
        delete data.items[id]
        this._setTodoData(req.user.username, data)
        if (span) span.end()
        this._logOperation(OPERATION_DELETE, req.user.username, id)
        res.status(204)
        res.send()
    }
...

Los logs de las varias operaciones de la aplicación se envían a través de una cola Redis al microservicio en Python:

...
_logOperation(opName, username, todoId) {
 var span = apm.startSpan('logging-operation')
 this._redisClient.publish(
   this._logChannel,
   JSON.stringify({
     opName,
     username,
     todoId,
     spanTransaction: span.transaction
   }),
   function(err) {
     if (span) span.end()
     if (err) {
       apm.captureError(err)
     }
   }
 )
}
...

Como se puede ver arriba, los datos enviados a Redis incluyen los campos opName y username, junto con el span.transaction que es un objeto que incluye la información de la traza padre, la cual es necesaria para unir las transacciones bajo la misma traza.

Aquí hay una muestra de spanTransaction, tal cómo se captura en el log en DEBUG que ya habíamos configurado al principio.

'spanTransaction': 
{
   "id":"4eb8801911b87fba",
   "trace_id":"5d9c555f6ef61f9d379e4a67270d2eb1",
   "parent_id":"a9f3ee75554369ab",
   "name":"GET unknown route (unnamed)",
   "type":"request",
   "subtype":"None",
   "action":"None",
   "duration":"None",
   "timestamp":1581287191572013,
   "result":"success",
   "sampled":True,
   "context":{
      "user":{
         "username":"johnd"
      },
      "tags":{
      },
      "custom":{
      },
      "request":{
         "http_version":"1.1",
         "method":"GET",
         "url":{
            "raw":"/todos",
            "protocol":"http:",
            "hostname":"127.0.0.1",
            "port":"8080",
            "pathname":"/todos",
            "full":"http://127.0.0.1:8080/todos"
         },
         "socket":{
            "remote_address":"::ffff:172.20.0.7",
            "encrypted":False
         },
         "headers":{
            "accept-language":"en-GB,en-US;q=0.9,en;q=0.8",
            "accept-encoding":"gzip, deflate, br",
            "referer":"http://127.0.0.1:8080/",
            "sec-fetch-mode":"cors",
            "sec-fetch-site":"same-origin",
            "elastic-apm-traceparent":"00-5d9c555f6ef61f9d379e4a67270d2eb1-a9f3ee75554369ab-01",
            "user-agent":"Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_3) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/79.0.3945.130 Safari/537.36",
            "authorization":"Bearer eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJleHAiOjE1ODE1NDYzOTEsImZpcnN0bmFtZSI6IkpvaG4iLCJsYXN0bmFtZSI6IkRvZSIsInJvbGUiOiJVU0VSIiwidXNlcm5hbWUiOiJqb2huZCJ9.Kv2e7E70ysbVvP-hKlG-RJyfKSibmiy8kCO-xqm3P6g",
            "x-requested-with":"XMLHttpRequest",
            "accept":"application/json, text/plain, */*",
            "connection":"close",
            "host":"127.0.0.1:8080"
         }
      },
      "response":{
         "status_code":200,
         "headers":{
         }
      }
   },
   "sync":False,
   "span_count":{
      "started":5
   }
}

Entre otras cosas, el log incluye el 'elastic-apm-traceparent': '00-5d9c555f6ef61f9d379e4a67270d2eb1-a9f3ee75554369ab-01'

Este es el campo que será utilizado por el microservicio en python, para asociar la transacción con la traza padre. Este campo garantizará que el rastreo distribuido sea implementado para las solicitudes de la aplicación “todo”, demostrando cómo atraviesan la interfaz de usuario, después la “todos-API” y luego, cómo se crean los logs, a través del procesador python.

Log-message-processor Python

El servicio “log-message-processor” no está basado en ningún framework, como por ejemplo, django o frasco los cuales están soportados por la auto-instrumentación con el agente de Python de Elastic APM.

Así que vamos a instrumentarlo de forma personalizada, utilizando la API del agente. El servicio está escrito en Python3 y es un consumidor sencillo, que recibe mensajes por la cola de Redis.

Para instalar el agente, sólo hay que añadirlo a este fichero log-message-processor/requirements.txt

elastic-apm

En el fichero log-message-processor/main.py es donde se importa el agente junto con el TraceParent del módulo elasticapm.utils.disttracing

...
import elasticapm
from elasticapm.utils.disttracing import TraceParent
from elasticapm import Client
client = Client({'SERVICE_NAME': 'python'})
...

Que vamos a necesitar para incluir el microservicio y sus transacciones en la traza distribuida.

Para capturar los tramos de la función “log_message”, se utiliza el método de decorador así:

...
@elasticapm.capture_span()
def log_message(message):
    time_delay = random.randrange(0, 2000)
    time.sleep(time_delay / 1000)
    print('message received after waiting for {}ms: {}'.format(time_delay, message))
...

Las transacciones comienzan y terminan alrededor de log_message(message), utilizando la API para las transacciones. El identificador principal de la traza se lee mediante el encabezado elastic-apm-traceparent(enviado a través de la cola redis) utilizando la API TraceParent

...
if __name__ == '__main__':
    redis_host = os.environ['REDIS_HOST']
    redis_port = int(os.environ['REDIS_PORT'])
    redis_channel = os.environ['REDIS_CHANNEL']
    pubsub = redis.Redis(host=redis_host, port=redis_port, db=0).pubsub()
    pubsub.subscribe([redis_channel])
    for item in pubsub.listen():
        try:
            message = json.loads(str(item['data'].decode("utf-8")))
        except Exception as e:
            log_message(e)
            continue
        spanTransaction = message['spanTransaction']
        trace_parent1 = spanTransaction['context']['request']['headers']['elastic-apm-traceparent']
        print('trace_parent_log: {}'.format(trace_parent1))
        trace_parent = TraceParent.from_string(trace_parent1)
        client.begin_transaction("logger-transaction", trace_parent=trace_parent)
        log_message(message)
        client.end_transaction('logger-transaction')
...

Las siguientes capturas de pantalla son ejemplos de las trazas distribuidas con sus transacciones y tramos. Muestran las solicitudes de creación y eliminación de los elementos de tarea, que fluyen a través de los microservicios, desde la interfaz de usuario, hasta la solicitud POST a la todos-api, los tramos relacionados para su creación y su registro, así como las transacciones y los tramos posteriores del “log-message-processor”.

Conclusión y próximos pasos

Hemos visto en detalle el proceso cómo instrumentar una aplicación de microservicios que utilizan diferentes lenguajes y frameworks.

Hay muchas áreas de Elastic APM que no hemos mencionado. Por ejemplo, no hemos visto cómo se pueden ver errores y métricas de la aplicación.

Además, se pueden correlacionar los logs de las aplicaciones con las trazas de APM. Esto significa que se puede inyectar fácilmente información de rastreo en los logs, lo que le permite explorarlos en la aplicación de Logs, y luego saltar directamente a los rastreos APM correspondientes.

Es más, los datos recopilados por APM también están disponibles en la aplicación SIEM

Otra área de interés es el uso de datos APM con Machine Learning. Se puede por ejemplo, detectar anomalías en los tiempos de respuesta de las transacciones.

Para cualquier duda sobre Elastic APM, puedes ponerte en contacto con Elastic, o hacer preguntas en el foro Discuss.