Desbloqueando el Event Loop

Unas semanitas después de haberme unido a Tiendanube nos encontramos con unos problemas de performance en uno de nuestros servicios de NodeJS que deberíamos diagnosticar y arreglar antes de estar expuestos a problemas de escalabilidad por el Hot Sale.

Cada un par de horas nuestros pods serían reciclados por Kubernetes por el alto consumo de CPU.

Recientemente migramos a DataDog y gracias al Dashboard y el Continuous Profiler pudimos ver que el consumo de CPU tenía picos bastantes frecuentes, el event loop tenía un delay bastante alto para la carga actual y encima el Garbage Collector hacía un stop the world bastante seguido 😂

Gracias al flame graph que DataDog elabora con su feature de Continuous Profiling, pudimos encontrar el problema bastante fácil ya que se podían ver las llamadas que estaban consumiendo un tiempo alto de CPU.

A simple vista había una función que estaba consumiendo el 10% del tiempo total de los requests, así que nos pusimos a investigar qué estaba pasando ahí.

Nuestros endpoints son bastante estándar: reciben un request, hacen llamadas a otros servicios y una vez que todo fue procesado correctamente devuelven una respuesta.

A fines de optimizar un poco la cantidad de objetos instanciados en éste flujo decidimos reciclar la instancia encargada de los requests http y no nos dimos cuenta que ésto era lo que estaba forzando el consumo elevado de CPU. Veamos el código:

export class HttpServiceAdapter {
 private readonly logger = new Nest.Logger(HttpServiceAdapter.name);
 constructor(
   private readonly httpService: HttpService,
   private readonly settings: Record<string, string>,
 ) {
   HttpServiceSetup.interceptAndTransformIOData(this.httpService);
 }
 public instanceFor(settings: Record<string, string>) {
   return new HttpServiceAdapter(this.httpService, {
     ...{},
     ...settings,
   });
 }
}

La clase HttpServiceAdapter implementa el método instanceFor() que:

• Genera una nueva instancia de la misma clase: con el objeto HttpService ya creado previamente ycon el objeto settings clonado
• Retorna la instancia

El módulo HttpServiceSetup.interceptAndTransformIOData hace lo siguiente:

import { HttpService } from '@nestjs/axios';
import { Logger } from '@nestjs/common';
import camelcaseKeys from 'camelcase-keys';
import snakecaseKeys from 'snakecase-keys';

const logger = new Logger('HttpServiceSetup');

function transformRequestDataToSnakeCase(req) {
 if (req.data) {
   req.data = snakecaseKeys(req.data, {
     deep: true,
   });
 }
 return req;
}

function transformResponseDataToCamelCase(res) {
 if (res.data) {
   res.data = camelcaseKeys(res.data, {
     deep: true,
   });
 }
 return res;
}

export const interceptAndTransformIOData = (httpService: HttpService): void => {
 httpService.axiosRef.interceptors.request.use(
   transformRequestDataToSnakeCase,
 );
 httpService.axiosRef.interceptors.response.use(
   transformResponseDataToCamelCase,
 );
};

Finalmente, mirando un poco la implementación de Axios, encontramos que cada vez que estamos llamando a interceptors.request.use() o interceptors.response.use() estaríamos modificando un array de funciones.

InterceptorManager.prototype.use = function use(fulfilled, rejected, options) {
 this.handlers.push({
   fulfilled: fulfilled,
   rejected: rejected,
   synchronous: options ? options.synchronous : false,
   runWhen: options ? options.runWhen : null,
 });
 return this.handlers.length - 1;

En definitiva: por cada llamada a HttpServiceAdapter#instanceFor() estaríamos llamando al constructor de HttpServiceAdapter que, al trabajar con la misma instancia de HttpService, estaría agregando dos funciones que alteran el request y el response body a un array. Estas funciones se estaban multiplicando y ejecutando tantas veces el constructor haya corrido en un pod.

Trabajamos en el fix que está un poco fuera de scope de éste blog, pero para los interesados en NestJS y Axios, se redujo a inicializar el HttpModule haciendo uso del transformRequest y transformResponse de Axios.

Luego de deployar el fix tanto el event loop como la CPU volvieron a niveles normales:

Éstos temas de performance son muy importantes para el crecimiento de la aplicación, algunas veces arrancamos con un producto menos maduro para recolectar feedback de utilización, sin embargo sabemos que es un conjunto de building blocks para evolucionar y mejorar siempre un poco más, conforme la necesidad del negocio. Y a vos, te gusta hacer performance troubleshooting? ¡Déjame tus comentarios!