Rastreamento de aplicações com NGINX e NGINX Plus

Liam CrillyDiretor Sênior de Gestão de Produtos

Como usar variáveis para o gerenciamento de desempenho de aplicações

As variáveis são um aspecto importante e, às vezes, negligenciado da configuração do NGINX. Com aproximadamente 150 variáveis disponíveis, há variáveis para aprimorar cada parte da sua configuração. Nesta publicação do blog, discutimos como usar variáveis do NGINX para rastreamento de aplicações e gerenciamento de desempenho de aplicações (APM), com foco na identificação de gargalos de desempenho na sua aplicação. Esta publicação se aplica tanto ao NGINX Open Source quanto ao NGINX Plus. Para simplificar, usaremos NGINX Plus ao longo do texto, exceto quando houver alguma diferença entre as duas versões.

O ambiente de entrega de aplicações

Em nosso ambiente de exemplo de entrega de aplicações, o NGINX Plus atua como proxy reverso para a nossa aplicação. A aplicação em si é composta por um frontend web, por trás do qual há vários microsserviços.

Rastreamento de solicitações de ponta a ponta

O NGINX Plus R10 (e o NGINX 1.11.0) introduz a variável $request_id, que é uma string de 32 caracteres hexadecimais gerada aleatoriamente e atribuída automaticamente a cada solicitação HTTP assim que ela chega (por exemplo, 444535f9378a3dfa1b8604bc9e05a303). Esse mecanismo aparentemente simples oferece uma ferramenta poderosa para rastreamento e solução de problemas. Ao configurar o NGINX Plus e todos os serviços de backend para repassar o valor de $request_id, você pode rastrear cada solicitação de ponta a ponta. Este exemplo de configuração é para o nosso servidor NGINX Plus de frontend.

upstream app_server {    server 10.0.0.1:80;
}

server {
    listen 80;
    add_header X-Request-ID $request_id; # Return to client
    location / {
        proxy_pass http://app_server;
        proxy_set_header X-Request-ID $request_id; # Pass to app server
    }
}

Para configurar o NGINX Plus para o rastreamento de solicitações, primeiro definimos o local de rede do servidor de aplicações no bloco upstream. Para simplificar, mostramos apenas um único server de aplicação aqui, mas normalmente usaríamos vários para garantir alta disponibilidade e balanceamento de carga.

O bloco server da aplicação define como o NGINX Plus processa as solicitações HTTP recebidas. A diretiva listen instrui o NGINX Plus a escutar na porta 80 – a porta padrão para tráfego HTTP, mas uma configuração de produção normalmente deve usar SSL/TLS para proteger os dados em trânsito.

A diretiva add_header envia o valor de $request_id de volta ao cliente como um cabeçalho personalizado na resposta. Isso é útil para testes e também para aplicativos clientes que geram seus próprios logs, como aplicativos móveis, permitindo correlacionar com precisão um erro no lado do cliente aos logs do servidor.

Por fim, o bloco location se aplica a todo o espaço da aplicação (/) e a diretiva proxy_pass simplesmente encaminha todas as solicitações ao servidor da aplicação. A diretiva proxy_set_header modifica a solicitação encaminhada adicionando um cabeçalho HTTP que é repassado à aplicação. Nesse caso, criamos um novo cabeçalho chamado X-Request-ID e atribuímos a ele o valor da variável $request_id. Assim, nossa aplicação recebe o ID da solicitação gerado pelo NGINX Plus.

Registro de $request_id de ponta a ponta

Nosso objetivo com o rastreamento de aplicações é identificar gargalos de desempenho no ciclo de vida do processamento de solicitações como parte do gerenciamento de desempenho de aplicações. Para isso, registramos eventos significativos durante o processamento, a fim de analisá-los posteriormente em busca de atrasos inesperados ou excessivos.

Configurando o NGINX Plus

Começamos configurando o servidor NGINX Plus de frontend para incluir $request_id em um formato de log personalizado, trace, usado para o arquivo access_trace.log.

log_format trace '$remote_addr - $remote_user [$time_local] "$request" '                 '$status $body_bytes_sent "$http_referer" "$http_user_agent" '
                 '"$http_x_forwarded_for" $request_id';

upstream app_server {
    server 10.0.0.1;
}

server {
    listen 80;
    add_header X-Request-ID $request_id; # Return to client
    location / {
        proxy_pass http://app_server;
        proxy_set_header X-Request-ID $request_id;        # Pass to app server
        access_log /var/log/nginx/access_trace.log trace; # Log $request_id
    }
}

Configurando a aplicação de backend

Passar o ID da solicitação para o seu aplicativo é muito útil, mas isso não ajuda de fato no rastreamento do aplicativo, a menos que ele faça algo com esse ID. Neste exemplo, temos um aplicativo Python gerenciado pelo uWSGI. Vamos modificar o ponto de entrada do aplicativo para capturar o ID da solicitação como uma variável de registro.

from uwsgi import set_logvar
def main(environ, start_response):
    set_logvar('requestid', environ['X_REQUEST_ID'])

Em seguida, podemos modificar a configuração do uWSGI para incluir o ID da solicitação no arquivo de log padrão.

log-format = %(addr) - %(user) [%(ltime)] "%(method) %(uri) %(proto)" %(status) %(size) "%(referer)" "%(uagent)" %(requestid)

Com essa configuração, agora estamos gerando arquivos de log que podem ser associados a uma única solicitação em diversos sistemas.

Entrada de log do NGINX:

172.17.0.1 - - [02/Aug/2016:14:26:50 +0000] "GET / HTTP/1.1" 200 90 "-" "-" "-" 5f222ae5938482c32a822dbf15e19f0f

Entrada de log da aplicação:

192.168.91.1 - - [02/Aug/2016:14:26:50 +0000] "GET / HTTP/1.0" 200 123 "-" "-" 5f222ae5938482c32a822dbf15e19f0f

Ao correlacionar as transações com os campos de ID da solicitação, ferramentas como Splunk e Kibana nos permitem identificar gargalos de desempenho no servidor da sua aplicação. Por exemplo, podemos pesquisar solicitações que levaram mais de dois segundos para serem concluídas. No entanto, a resolução de tempo padrão de um segundo dos carimbos de data e hora convencionais é insuficiente para a maioria das análises em situações reais.

Temporização de alta precisão

Para medir com precisão as solicitações de ponta a ponta, precisamos de carimbos de data e hora com precisão de milissegundos. Ao incluir a variável $msec nas entradas de log, obtemos uma resolução de milissegundos no carimbo de data e hora de cada entrada. Adicionar carimbos de data e hora com precisão de milissegundos ao log da nossa aplicação nos permite identificar solicitações que levaram mais de 200 milissegundos para serem concluídas, em vez de 2 segundos.

Mas, mesmo assim, não temos uma visão completa, pois o NGINX Plus registra o carimbo de data e hora $msec somente ao final do processamento de cada solicitação. Felizmente, há várias outras variáveis de tempo do NGINX Plus com precisão de milissegundos que nos dão mais informações sobre o processamento em si:

• $request_time – Tempo total da solicitação, começando quando o NGINX Plus lê o primeiro byte do cliente e terminando quando o NGINX Plus envia o último byte do corpo da resposta
• $upstream_connect_time – Tempo gasto para estabelecer uma conexão com o servidor upstream
• $upstream_header_time – Tempo entre o estabelecimento de uma conexão com o servidor upstream e o recebimento do primeiro byte do cabeçalho da resposta
• $upstream_response_time – Tempo entre o estabelecimento de uma conexão com o servidor upstream e o recebimento do último byte do corpo da resposta

Para obter informações detalhadas sobre essas variáveis de tempo, consulte Como usar os logs do NGINX para monitorar o desempenho de aplicações.

Vamos ampliar nossa diretiva log_format para incluir todas essas variáveis de tempo de alta precisão em nosso formato de log trace.

log_format trace '$remote_addr - $remote_user [$time_local] "$request" $status '                 '$body_bytes_sent "$http_referer" "$http_user_agent" '
                 '"$http_x_forwarded_for" $request_id $msec $request_time '
                 '$upstream_connect_time $upstream_header_time $upstream_response_time';

Usando nossa ferramenta de análise de logs preferida, podemos extrair os valores das variáveis e realizar o cálculo a seguir para verificar quanto tempo o NGINX Plus levou para processar a solicitação antes de se conectar ao servidor de aplicações:

NGINX Plus processing time = $request_time - $upstream_connect_time - $upstream_response_time

Também podemos pesquisar os valores mais altos de $upstream_response_time para verificar se estão associados a URIs ou servidores upstream específicos. Em seguida, podemos compará-los com as entradas do log da aplicação que tenham o mesmo ID de solicitação.

Conclusão

A utilização da nova variável $request_id e de algumas ou de todas as variáveis com precisão de milissegundos pode fornecer informações valiosas sobre os gargalos de desempenho da sua aplicação, aprimorando o gerenciamento de desempenho sem a necessidade de recorrer a agentes e plug-ins pesados.

Experimente você mesmo o rastreamento de aplicações com o NGINX Plus: comece sua avaliação gratuita de 30 dias hoje mesmo ou entre em contato conosco para conversar sobre seus casos de uso.

Sobre o autor

Liam CrillyDiretor Sênior de Gestão de Produtos

Mais publicações de Liam Crilly