`systemtap-toolkit` y `stapxx`: ¿Cómo usar datos para resolver problemas difíciles?
API7.ai
December 22, 2022
Como se introdujo en el artículo anterior, como ingenieros de desarrollo del lado del servidor, no profundizamos en el aprendizaje de herramientas de depuración dinámica, sino que nos mantenemos principalmente en el nivel de uso y, como máximo, escribimos algunos scripts simples. Los aspectos más profundos, como la caché de la CPU, la arquitectura, el compilador, etc., son dominio de los ingenieros de rendimiento.
En OpenResty hay dos proyectos de código abierto: openresty-systemtap-toolkit y stapxx. Son conjuntos de herramientas basados en systemtap para el análisis y diagnóstico en tiempo real de NGINX y OpenResty. Cubren características y escenarios de depuración comunes, como on-CPU, off-CPU, diccionarios compartidos, recolección de basura, latencia de solicitudes, agrupación de memoria, agrupación de conexiones, acceso a archivos, entre otros.
En este artículo, revisaremos estas herramientas y su uso correspondiente, para ayudarnos a encontrar rápidamente herramientas que nos permitan localizar problemas cuando nos enfrentemos a la resolución de problemas con NGINX y OpenResty. En el mundo de OpenResty, aprender a usar estas herramientas es una forma segura de avanzar y una manera muy efectiva de comunicarse con otros desarrolladores; después de todo, los datos generados por las herramientas serán más precisos y detallados que lo que podríamos describir con palabras.
Sin embargo, es esencial tener en cuenta que, a partir de la versión 1.15.8 de OpenResty, el modo LuaJIT GC64 está habilitado por defecto, pero openresty-systemtap-toolkit y stapxx no siguen los cambios correspondientes, lo que hará que las herramientas internas no funcionen correctamente. Por lo tanto, es mejor usar estas herramientas en la versión antigua 1.13 de OpenResty.
La mayoría de los contribuyentes de proyectos de código abierto trabajan a tiempo parcial y no están obligados a mantener las herramientas funcionando, algo que debemos tener en cuenta al usar proyectos de código abierto.
Ejemplo: shared dict
Comencemos con una herramienta que probablemente nos sea más familiar y fácil de usar, ngx-lua-shdict, como ejemplo para iniciar esta publicación.
ngx-lua-shdict es una herramienta que analiza los shared dicts de NGINX y rastrea sus operaciones. Puedes usar la opción -f para especificar el dict y la key para obtener los datos en el shared dict. La opción --raw te permite exportar el valor en bruto de la key especificada.
El siguiente es un ejemplo de línea de comandos para obtener datos de un shared dict.
# Suponiendo que el PID del Worker de NGINX es 5050
$ ./ngx-lua-shdict -p 5050 -f --dict dogs --key Jim --luajit20
Tracing 5050 (/opt/nginx/sbin/nginx)...
type: LUA_TBOOLEAN
value: true
expires: 1372719243270
flags: 0xa
De manera similar, podemos usar la opción -w para rastrear las escrituras en el dict para una key dada:
$./ngx-lua-shdict -p 5050 -w --key Jim --luajit20
Tracing 5050 (/opt/nginx/sbin/nginx)...
Hit Ctrl-C to end
set Jim exptime=4626322717216342016
replace Jim exptime=4626322717216342016
^C
Veamos cómo se implementa esta herramienta. ngx-lua-shdict es un script en Perl, pero la implementación no tiene nada que ver con Perl, que solo se usa para generar el script stap y ejecutarlo.
open my $in, "|stap $stap_args -x $pid -" or die "Cannot run stap: $!\n";
Podríamos escribirlo en Python, PHP, Go o cualquier lenguaje que nos guste. El punto clave en el script stap es la siguiente línea de código:
probe process("$nginx_path").function("ngx_http_lua_shdict_set_helper")
Esta es la probe que mencionamos antes, que sondea la función ngx_http_lua_shdict_set_helper. Las llamadas a esta función están todas en el archivo lua-nginx-module/src/ngx_http_lua_shdict.c del módulo lua-nginx-module.
static int
ngx_http_lua_shdict_add(lua_State *L)
{
return ngx_http_lua_shdict_set_helper(L, NGX_HTTP_LUA_SHDICT_ADD);
}
static int
ngx_http_lua_shdict_safe_add(lua_State *L)
{
return ngx_http_lua_shdict_set_helper(L, NGX_HTTP_LUA_SHDICT_ADD
|NGX_HTTP_LUA_SHDICT_SAFE_STORE);
}
static int
ngx_http_lua_shdict_replace(lua_State *L)
{
return ngx_http_lua_shdict_set_helper(L, NGX_HTTP_LUA_SHDICT_REPLACE);
}
De esta manera, podemos rastrear todas las operaciones del diccionario compartido simplemente sondeando esta función.
on-CPU, off-CPU
Al usar OpenResty, el problema más común que encontramos es el rendimiento. Hay dos tipos principales de bajo rendimiento, es decir, bajo QPS: uso de CPU demasiado alto y uso de CPU demasiado bajo. El primer cuello de botella puede deberse a no usar los métodos de optimización de rendimiento que mencionamos anteriormente, mientras que el segundo puede deberse a funciones bloqueantes. Los gráficos de llamadas (flame graphs) on-CPU y off-CPU correspondientes pueden ayudarnos a identificar la causa raíz.
Para generar gráficos de llamadas on-CPU a nivel de C, necesitas usar sample-bt en systemtap-toolkit; mientras que los gráficos de llamadas on-CPU a nivel de Lua son generados por lj-lua-stacks en stapxx.
Tomemos sample-bt como ejemplo de cómo usarlo. sample-bt es un script que muestrea la pila de llamadas de cualquier proceso de usuario que especifiquemos (no solo procesos de NGINX y OpenResty).
Por ejemplo, podemos muestrear un proceso Worker de NGINX en ejecución (con un PID de 8736) durante 5 segundos con el siguiente código:
$ ./sample-bt -p 8736 -t 5 -u > a.bt
WARNING: Tracing 8736 (/opt/nginx/sbin/nginx) in user-space only...
WARNING: Missing unwind data for module, rerun with 'stap -d stap_df60590ce8827444bfebaf5ea938b5a_11577'
WARNING: Time's up. Quitting now...(it may take a while)
WARNING: Number of errors: 0, skipped probes: 24
Este comando genera el archivo de resultados a.bt, que puede usarse para generar un gráfico de llamadas usando el conjunto de herramientas FlameGraph:
stackcollapse-stap.pl a.bt > a.cbt
flamegraph.pl a.cbt > a.svg
El archivo a.svg es el gráfico de llamadas generado, que podemos abrir en el navegador para ver. Sin embargo, durante el período de muestreo, debemos mantener un cierto número de solicitudes. De lo contrario, no habrá forma de generar el gráfico de llamadas si el recuento de muestras es 0.
A continuación, veremos cómo muestrear off-CPU, usando el script sample-bt-off-cpu en systemtap-toolkit, que es similar a sample-bt, de la siguiente manera:
$ ./sample-bt-off-cpu -p 10901 -t 5 > a.bt
WARNING: Tracing 10901 (/opt/nginx/sbin/nginx)...
WARNING: _stp_read_address failed to access memory location
WARNING: Time's up. Quitting now...(it may take a while)
WARNING: Number of errors: 0, skipped probes: 23
En stapxx, la herramienta para analizar la latencia es epoll-loop-blocking-distr, que muestrea el proceso de usuario especificado y genera la distribución de latencia entre llamadas sucesivas al sistema epoll_wait.
$ ./samples/epoll-loop-blocking-distr.sxx -x 19647 --arg time=60
Start tracing 19647...
Please wait for 60 seconds.
Distribution of epoll loop blocking latencies (in milliseconds)
max/avg/min: 1097/0/0
value |-------------------------------------------------- count
0 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 18471
1 |@@@@@@@@ 3273
2 |@ 473
4 | 119
8 | 67
16 | 51
32 | 35
64 | 20
128 | 23
256 | 9
512 | 2
1024 | 2
2048 | 0
4096 | 0
Como podemos ver, esta salida muestra que la gran mayoría de las demoras son menores a 1 ms, pero hay algunas que superan los 200 ms, y estas son las que debemos vigilar.
Seguimiento de Upstream y Fases
Además de los problemas de rendimiento que pueden ocurrir en el código de OpenResty en sí, cuando OpenResty se comunica con servicios upstream a través de módulos como cosocket o proxy_pass, si el servicio upstream tiene una gran latencia, también puede tener un impacto significativo en el rendimiento general.
En este caso, podemos usar las herramientas ngx-lua-tcp-recv-time, ngx-lua-udp-recv-time y ngx-single-req-latency para el análisis. Aquí hay un ejemplo de ngx-single-req-latency.
Esta herramienta no es exactamente igual a la mayoría de las herramientas dentro del conjunto. La mayoría de las otras herramientas se basan en una gran cantidad de muestras y análisis estadísticos para llegar a una conclusión matemática sobre la distribución. En cambio, ngx-single-req-latency analiza solicitudes individuales y rastrea el tiempo dedicado a solicitudes individuales en varias fases de OpenResty, como las fases rewrite, access y content, así como en el upstream.
Podemos ver un ejemplo de código específico:
# Haciendo visible la herramienta ./stap++ en PATH:
$ export PATH=$PWD:$PATH
# Suponiendo que el PID de un proceso Worker de nginx es 27327
$ ./samples/ngx-single-req-latency.sxx -x 27327
Start tracing process 27327 (/opt/nginx/sbin/nginx)...
POST /api_json
total: 143596us, accept() ~ header-read: 43048us, rewrite: 8us, pre-access: 7us, access: 6us, content: 100507us
upstream: connect=29us, time-to-first-byte=99157us, read=103us
$ ./samples/ngx-single-req-latency.sxx -x 27327
Start tracing process 27327 (/opt/nginx/sbin/nginx)...
GET /robots.txt
total: 61198us, accept() ~ header-read: 33410us, rewrite: 7us, pre-access: 7us, access: 5us, content: 27750us
upstream: connect=30us, time-to-first-byte=18955us, read=96us
Esta herramienta rastreará la primera solicitud que encuentre después de iniciarse. La salida es muy similar a opentracing, e incluso podemos pensar en systemtap-toolkit y stapxx como versiones no intrusivas de APM (Gestión del Rendimiento de Aplicaciones) en OpenResty.
Resumen
Además de las herramientas comunes que he mencionado hoy, OpenResty naturalmente proporciona muchas más herramientas que puedes explorar y aprender por tu cuenta.
Hay una diferencia más significativa entre OpenResty y otros lenguajes y plataformas de desarrollo en términos de tecnología de rastreo, que podemos apreciar lentamente.
Mantén el código limpio y estable, no agregues sondas a él, sino muestréalo a través de técnicas de rastreo dinámico externas.
¿Qué herramientas has usado para rastrear y analizar problemas mientras usas OpenResty? Te invitamos a compartir este artículo, y así compartiremos y progresaremos juntos.