`systemtap-toolkit` e `stapxx`: Como usar dados para resolver problemas difíceis?
API7.ai
December 22, 2022
Como apresentado no artigo anterior, como engenheiros de desenvolvimento do lado do servidor, não nos aprofundamos no aprendizado de ferramentas de depuração dinâmica, mas geralmente nos limitamos ao nível de uso e, no máximo, escrevemos alguns scripts simples. O nível mais baixo, como cache da CPU, arquitetura, compilador, etc., é o domínio dos engenheiros de desempenho.
Existem dois projetos de código aberto no OpenResty: openresty-systemtap-toolkit e stapxx. Eles são conjuntos de ferramentas baseados em systemtap para análise e diagnóstico em tempo real do NGINX e OpenResty. Eles podem cobrir recursos e cenários de depuração comuns, como on-CPU, off-CPU, dicionário compartilhado, coleta de lixo, latência de solicitação, pooling de memória, pooling de conexões, acesso a arquivos, entre outros.
Neste artigo, vamos explorar essas ferramentas e seus usos correspondentes, para nos ajudar a localizar rapidamente problemas quando enfrentamos questões de solução de problemas com o NGINX e OpenResty. No mundo do OpenResty, aprender a usar essas ferramentas é uma maneira infalível de se destacar e uma forma muito eficaz de se comunicar com outros desenvolvedores - afinal, os dados gerados pelas ferramentas serão mais precisos e detalhados do que podemos descrever em palavras.
No entanto, é essencial observar que o modo LuaJIT GC64 está habilitado por padrão na versão 1.15.8 do OpenResty, mas o openresty-systemtap-toolkit e o stapxx não acompanharam as mudanças correspondentes, o que fará com que as ferramentas internas não funcionem corretamente. Portanto, é melhor usar essas ferramentas na versão antiga 1.13 do OpenResty.
A maioria dos contribuidores de projetos de código aberto trabalha em tempo parcial e não tem a obrigação de manter as ferramentas funcionando, o que precisamos ter em mente ao usar projetos de código aberto.
Exemplo: shared dict
Vamos começar com uma ferramenta que provavelmente é a mais familiar e fácil de começar, o ngx-lua-shdict, como exemplo para iniciar o post de hoje.
ngx-lua-shdict é uma ferramenta que analisa os shared dicts do NGINX e rastreia suas operações. Você pode usar a opção -f para especificar o dict e a key para obter os dados no shared dict. A opção --raw permite exportar o valor bruto da key especificada.
A seguir está um exemplo de linha de comando para obter dados de um shared dict.
# Supondo que o PID do Worker do NGINX seja 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
Da mesma forma, podemos usar a opção -w para rastrear as escritas no dict para uma key específica:
$./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
Vamos ver como essa ferramenta é implementada. ngx-lua-shdict é um script Perl, mas a implementação não tem nada a ver com Perl, que é usado apenas para gerar o script stap e executá-lo.
open my $in, "|stap $stap_args -x $pid -" or die "Cannot run stap: $!\n";
Poderíamos escrevê-lo em Python, PHP, Go ou qualquer linguagem que preferirmos. O ponto chave no script stap é a seguinte linha de código:
probe process("$nginx_path").function("ngx_http_lua_shdict_set_helper")
Este é o probe que mencionamos antes, sondando a função ngx_http_lua_shdict_set_helper. As chamadas para essa função estão todas no arquivo lua-nginx-module/src/ngx_http_lua_shdict.c do 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);
}
Dessa forma, podemos rastrear todas as operações do shared dict simplesmente sondando essa função.
on-CPU, off-CPU
Ao usar o OpenResty, o problema mais comum que encontramos deve ser o de desempenho. Existem dois tipos principais de baixo desempenho, ou seja, baixo QPS: uso de CPU muito alto e uso de CPU muito baixo. O primeiro gargalo pode ser devido ao não uso dos métodos de otimização de desempenho que apresentamos anteriormente, enquanto o segundo pode ser devido a funções bloqueantes. Os gráficos de chamas on-CPU e off-CPU correspondentes podem nos ajudar a identificar a causa raiz final.
Para gerar gráficos de chamas on-CPU em nível C, você precisa usar o sample-bt no systemtap-toolkit; enquanto os gráficos de chamas on-CPU em nível Lua são gerados pelo lj-lua-stacks no stapxx.
Vamos usar o sample-bt como exemplo de como usá-lo. sample-bt é um script que amostra a pilha de chamadas de qualquer processo de usuário que especificarmos (não apenas processos NGINX e OpenResty).
Por exemplo, podemos amostrar um processo Worker do NGINX em execução (com um PID de 8736) por 5 segundos com o seguinte 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
Ele gera o arquivo de resultado a.bt, que pode ser usado para gerar um gráfico de chamas usando o conjunto de ferramentas FlameGraph:
stackcollapse-stap.pl a.bt > a.cbt
flamegraph.pl a.cbt > a.svg
O a.svg é o gráfico de chamas gerado, que podemos abrir no navegador para visualizar. No entanto, durante o período de amostragem, devemos manter um certo número de solicitações. Caso contrário, não haverá como gerar o gráfico de chamas se a contagem de amostras for 0.
A seguir, veremos como amostrar off-CPU, usando o script sample-bt-off-cpu no systemtap-toolkit, que é semelhante ao sample-bt, da seguinte forma:
$ ./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
No stapxx, a ferramenta para analisar a latência é o epoll-loop-blocking-distr, que amostra o processo de usuário especificado e gera a distribuição de latência entre chamadas sucessivas do 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, essa saída mostra que a grande maioria das latências é inferior a 1 ms, mas há algumas acima de 200 ms, e essas são as que devemos observar.
Rastreamento de Upstream e Fases
Além dos problemas de desempenho que podem ocorrer no próprio código do OpenResty, quando o OpenResty se comunica com serviços upstream através de módulos como cosocket ou proxy_pass, se o serviço upstream em si tiver uma grande latência, isso também pode ter um impacto significativo no desempenho geral.
Nesse caso, podemos usar as ferramentas ngx-lua-tcp-recv-time, ngx-lua-udp-recv-time e ngx-single-req-latency para análise. Aqui está um exemplo de ngx-single-req-latency.
Essa ferramenta não é exatamente igual à maioria das ferramentas dentro do conjunto. A maioria das outras ferramentas é baseada em um grande número de amostras e análise estatística para chegar a uma conclusão matemática sobre a distribuição. Em vez disso, o ngx-single-req-latency analisa solicitações individuais e rastreia o tempo gasto em solicitações individuais em várias fases no OpenResty, como as fases rewrite, access e content, bem como upstream.
Podemos ver um exemplo de código específico:
# Tornando a ferramenta ./stap++ visível no PATH:
$ export PATH=$PWD:$PATH
# Supondo que o PID de um processo Worker do nginx seja 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
Essa ferramenta rastreará a primeira solicitação que encontrar após iniciar. A saída é muito semelhante ao opentracing, e podemos até pensar no systemtap-toolkit e no stapxx como versões não intrusivas de APM (Gerenciamento de Desempenho de Aplicações) no OpenResty.
Resumo
Além das ferramentas comuns que falei hoje, o OpenResty naturalmente fornece muitas outras ferramentas que você pode explorar e aprender por conta própria.
Há uma diferença significativa entre o OpenResty e outras linguagens e plataformas de desenvolvimento em termos de tecnologia de rastreamento, que podemos apreciar aos poucos.
Mantenha o código limpo e estável, não adicione sondas a ele, mas amostre-o através de técnicas de rastreamento dinâmico externas.
Quais ferramentas você usou para rastrear e analisar problemas ao usar o OpenResty? Você é bem-vindo a compartilhar este artigo, e vamos compartilhar e progredir juntos.