Profiling de execução e rede no Linux: dissecando o curl e chamadas de sistema

Quando executo rotinas e scripts de automação no Linux, cedo ou tarde recebo o clássico aviso: "o script está demorando muito" ou "a API externa está lenta". Minha primeira reação no passado era colocar um time na frente do comando e olhar apenas o tempo total decorrido.

Em ambientes de produção, o tempo total é uma métrica vazia. Ele diz que demorou dez segundos, mas não revela se o processo passou esse tempo travado em I/O de disco, dormindo esperando pacotes TCP ou sofrendo corte de CPU pelo kernel. Precisamos de granularidade na pilha do sistema operacional.

Neste artigo, documentei como medir, perfilar e entender o tempo de execução de comandos no Linux. Utilizei como caso prático uma consulta de certificados via curl no serviço crt.sh para um domínio alvo (https://crt.sh/?q=exemplo.com).

1. O engano comum: shell built-in vs. binário GNU#

A primeira distinção prática que vale a pena dominar é a diferença entre a palavra reservada do interpretador e o binário do sistema operacional.

O built-in do Bash (time)#

Quando digito time comando, o Bash intercepta a chamada. Ele não cria um processo separado para medir o tempo. O próprio shell marca o carimbo de data/hora interno, executa o comando alvo via fork e exec, e calcula a diferença. É rápido para testes informais, mas não entrega detalhes de consumo de recursos.

O binário do GNU (/usr/bin/time)#

Para diagnóstico detalhado, aciono o executável do GNU, documentado no manual oficial do GNU time:

\time -v curl -s "https://crt.sh/?q=exemplo.com" > /dev/null

A barra invertida antes do time instrui o shell a ignorar o comando interno ou qualquer alias, executando diretamente o binário /usr/bin/time presente no $PATH.

O que o Kernel faz em modo detalhado#

Ao chamar /usr/bin/time -v, o processo pai realiza uma bifurcação (fork). O processo filho carrega o curl através da chamada de sistema execve(). Enquanto o filho roda, o pai aguarda bloqueado na chamada de sistema wait4().

Quando o curl encerra (seja com sucesso ou recebendo um sinal como SIGKILL), a chamada wait4() retorna preenchendo a estrutura struct rusage em C (definida em <sys/resource.h>), detalhada no manual de getrusage do Linux. Essa estrutura lê os contadores de hardware e memória direto do bloco de controle do processo (PCB) que acabou de finalizar.

Na saída gerada, quatro indicadores merecem atenção imediata:

• User time e System time: O tempo em modo usuário reflete as instruções executadas diretamente pela aplicação na CPU (como computação matemática, parsing de JSON ou decodificação de strings). O tempo de sistema (sys) contabiliza o tempo que a CPU passou executando código do kernel em nome do processo (atendendo chamadas de sistema como alocação de páginas de memória ou gravação em descritores de arquivo).
• Maximum resident set size (ru_maxrss): No Linux, indica o pico de memória RAM física ocupada pelo processo durante toda a sua existência (mensurado em kilobytes). Se o processo sofrer vazamento de memória ou alocações desproporcionais, esse contador entrega o teto atingido.
• Major Page Faults (ru_majflt): Se esse contador for alto, indica que o binário do curl ou suas bibliotecas compartilhadas (libcurl.so, libssl.so) não estavam no Page Cache da memória RAM. O kernel precisou buscar blocos fisicamente no disco para colocá-los na memória. Isso também ocorre quando o servidor passa por pressão extrema de memória e usa swap.
• Involuntary Context Switches (ru_nivcsw): Mostra quantas vezes o escalonador do Linux retirou o processo da CPU à força porque o tempo de fatia (timeslice) expirou ou uma interrupção de hardware prioritária exigiu atenção. Valores altos sugerem disputa pesada por CPU na máquina.

2. Rastreabilidade de rede: o motor interno do curl#

O /usr/bin/time nos dá a visão dos recursos computacionais da máquina, mas não enxerga o que acontece dentro da conexão TCP/IP. O curl se apoia em bibliotecas externas como OpenSSL para criptografia e a própria libcurl para o protocolo HTTP.

Para decompor as etapas da latência de rede, utilizo a opção de formatação -w (write-out) do utilitário, cujas variáveis são detalhadas na página oficial de manual do curl:

curl -o /dev/null -s -w "\
\n--------------------------------------\n\
DNS Lookup:        %{time_namelookup}s\n\
TCP Connect:       %{time_connect}s\n\
TLS Handshake:     %{time_appconnect}s\n\
Pre-Transfer:      %{time_pretransfer}s\n\
Start Transfer:    %{time_starttransfer}s\n\
--------------------------------------\n\
Total Time:        %{time_total}s\n" \
"https://crt.sh/?q=exemplo.com"

O que cada indicador mede na prática#

1. time_namelookup (Resolução DNS):

Mede o tempo gasto para resolver o nome de domínio em endereço IP. Na libcurl, essa etapa passa pela função Curl_resolv(), que delega para a chamada getaddrinfo() da biblioteca C padrão (glibc). Se esse tempo estiver alto de forma intermitente, audito o cache local do resolvedor com resolvectl statistics (em distribuições com systemd-resolved) ou verifico tempos limite configurados em /etc/resolv.conf.

1. time_connect (Conexão TCP):

Mede o tempo decorrido desde o início até o término do aperto de mão TCP triplo (SYN, SYN-ACK, ACK) com o host remoto ou proxy.

1. time_appconnect (Negociação TLS):

Mede o tempo até a conclusão do aperto de mão criptográfico. Esse intervalo reflete a execução interna de SSL_do_handshake() no OpenSSL. Lentidões anormais aqui apontam para troca de certificados muito pesados com fragmentação de pacotes (vale checar o MTU da interface de rede com ip link show) ou suites de criptografia lentas.

1. time_starttransfer (Tempo até o primeiro byte / TTFB):

A conexão TCP já foi estabelecida, a camada TLS já foi fechada e a requisição HTTP GET já foi enviada. O tempo restante até o primeiro byte de resposta chegar reflete a latência de trânsito mais o tempo de processamento interno do servidor de destino. No caso do crt.sh, esse costuma ser o maior intervalo, pois o banco de dados remoto precisa processar a consulta SQL antes de transmitir o resultado.

Decompondo os deltas reais de latência#

As métricas nativas do curl -w são cumulativas: cada variável registra o tempo decorrido desde o início da operação ($t_0$). Para saber exatamente onde o tempo foi gasto de forma independente, precisamos calcular as diferenças (deltas):

• Latência pura de DNS: $\Delta_{\text{DNS}} = \text{time\_namelookup}$
• Aperto de mão TCP: $\Delta_{\text{TCP}} = \text{time\_connect} - \text{time\_namelookup}$
• Handshake TLS: $\Delta_{\text{TLS}} = \text{time\_appconnect} - \text{time\_connect}$
• Envio da requisição: $\Delta_{\text{REQ}} = \text{time\_pretransfer} - \text{time\_appconnect}$
• Processamento remoto (TTFB líquido): $\Delta_{\text{SERVER}} = \text{time\_starttransfer} - \text{time\_pretransfer}$
• Download do payload: $\Delta_{\text{DATA}} = \text{time\_total} - \text{time\_starttransfer}$

Podemos automatizar esse cálculo em um pipeline com awk:

curl -s -w "%{time_namelookup} %{time_connect} %{time_appconnect} %{time_pretransfer} %{time_starttransfer} %{time_total}\n" \
     -o /dev/null "https://crt.sh/?q=exemplo.com" | awk '{
    printf "DNS Lookup:      %.4f s\n", $1
    printf "TCP Handshake:   %.4f s\n", $2 - $1
    printf "TLS Handshake:   %.4f s\n", $3 - $2
    printf "Request Send:    %.4f s\n", $4 - $3
    printf "Server Wait:     %.4f s\n", $5 - $4
    printf "Data Transfer:   %.4f s\n", $6 - $5
    printf "Total Elapsed:   %.4f s\n", $6
}'

Se o teste revelar que DNS Lookup demorou 5 segundos cravados enquanto as outras etapas demoraram milissegundos, o problema não tem relação com o servidor de destino, mas sim com o comportamento de timeout de servidores DNS secundários na máquina local.

3. Profiling aprofundado: dissecando chamadas de sistema com strace#

Quando um comando engasga e preciso comprovar se o gargalo é local ou do servidor remoto, o strace se torna a ferramenta mais conclusiva do terminal, conforme descrito na documentação do strace.

Para obter uma visão consolidada do tempo gasto por tipo de chamada:

strace -c curl -s "https://crt.sh/?q=exemplo.com" > /dev/null

O parâmetro -c agrupa o tempo total por chamada de sistema em uma tabela final, evitando que milhares de linhas poluam a tela.

Quando preciso de inspeção em tempo real focada em eventos críticos:

strace -T -e trace=network,file curl -s "https://crt.sh/?q=exemplo.com" > /dev/null

A flag -T exibe o tempo consumido por cada syscall individualmente, restringindo o rastreio a operações de rede e leitura de arquivos.

Diagnósticos comuns identificados no strace#

• Tempo acumulado em poll, select ou epoll_wait: O binário do curl não está calculando nada; a thread está em repouso aguardando a placa de rede sinalizar a chegada de dados no socket TCP. Se o tempo total do comando for longo e a maior parte estiver concentrada aqui, o gargalo é externo: lentidão de rede ou demora do backend remoto em responder.
• Tempo elevado em openat ou newfstatat: O curl lê o repositório local de autoridades certificadoras para validar o certificado SSL (/etc/ssl/certs/ ou /etc/pki/tls/certs/). Se o disco do servidor local sofrer com filas de I/O lentas, o atraso decorre da leitura local dos certificados, não da conexão com a internet.

O custo do strace e o overhead de ptrace#

Um aviso indispensável para quem atua em produção: o strace se apoia na chamada de sistema ptrace(2). A cada chamada de sistema executada pelo processo monitorado, o kernel interrompe o processo alvo, realiza a troca de contexto para o strace inspecionar os registradores na entrada da syscall, executa a instrução no kernel e interrompe o processo novamente na saída para capturar o código de retorno.

Em processos com alto volume de operações de E/S ou conexões concorrentes, o strace pode desacelerar a execução em mais de 10 a 50 vezes, gerando um clássico efeito Heisenberg (onde o ato de observar altera o tempo medido).

Para auditorias de altíssima performance em produção sem overhead abusivo, prefira ferramentas modernas como perf trace ou utilitários baseados em eBPF (bpftrace), que agregam dados diretamente no espaço de kernel sem forçar context switches contínuos.

4. Analisando cenários de borda#

Em produção, não dá para se apoiar apenas no cenário ideal. Existem situações onde os números parecem contraditórios.

Limitação de CPU por cgroups (throttling)#

Um caso comum: você roda o /usr/bin/time e o tempo real marca 10 segundos, mas a soma de tempo de usuário com tempo de kernel (user + sys) mal atinge 0.4 segundos. Ao mesmo tempo, o teste com curl -w não indica problemas graves de rede.

Isso costuma indicar estrangulamento de CPU imposto pelo kernel através de cotas de cgroups (muito comum em containers Docker, Podman, Kubernetes ou limites LVE em servidores compartilhados). O processo fica pausado aguardando novas fatias de processamento da cota de tempo CFS (Completely Fair Scheduler).

A inspeção varia conforme a versão do cgroups montada no sistema:

• cgroups v1: inspecione /sys/fs/cgroup/cpu,cpuacct/cpu.stat e avalie os contadores nr_throttled e throttled_time.
• cgroups v2: consulte /sys/fs/cgroup/<slice>/cpu.stat e observe nr_throttled e throttled_usec.

O falso positivo com erros HTTP rápidos#

Bancos de dados sobrecarregados frequentemente abortam consultas demoradas e devolvem erros como HTTP 502 (Bad Gateway) ou 504 através de proxies reversos. Nesse caso, a requisição fecha rapidamente (por exemplo, em 800 milissegundos), gerando uma falsa impressão de bom desempenho se você olhar apenas o tempo total de execução.

Para evitar que scripts de monitoramento assumam que respostas rápidas com erro são sucessos, sempre force a validação do código de status:

TIMEFORMAT='Real: %R | User: %U | Sys: %S'
HTTP_STATUS=$(curl -o /dev/null -s -w "%{http_code}" "https://crt.sh/?q=exemplo.com")

if [ "$HTTP_STATUS" -eq 200 ]; then
    echo "Serviço íntegro. Executando medição:"
    time curl -s "https://crt.sh/?q=exemplo.com" > /dev/null
else
    logger -p daemon.error "Falha de conectividade detectada. HTTP Status: $HTTP_STATUS."
fi

Gargalos silenciosos de DNS com dual-stack (IPv4/IPv6)#

Outro caso de borda frequente no Linux ocorre quando a máquina possui suporte a IPv6 habilitado na pilha de rede, mas a conectividade IPv6 externa não possui rota válida. A função getaddrinfo() do sistema operacional dispara consultas concorrentes para registros A (IPv4) e AAAA (IPv6).

Se o servidor DNS corporativo ou o roteador descartar silenciosamente os pacotes AAAA, o resolvedor local aguarda o timeout integral (tipicamente 5 segundos configurados em /etc/resolv.conf) antes de retornar apenas a resposta IPv4. O comando curl funciona, mas cada requisição perde 5 segundos cravados antes de iniciar a conexão.

Para diagnosticar se o atraso provém da resolução de nomes, force a resolução restrita a IPv4 com a flag -4:

curl -4 -o /dev/null -s -w "DNS: %{time_namelookup}s | Total: %{time_total}s\n" "https://crt.sh/?q=exemplo.com"

Se o time_namelookup cair imediatamente de 5 segundos para 0.02 segundos, a causa-raiz é a falha no descarte de pacotes IPv6 na infraestrutura de rede local.

O que fica de diagnóstico e síntese prática#

Avaliar o tempo de execução de um comando no Linux exige entender em qual camada o processo gasta seus ciclos: calculando dados em modo usuário, operando sockets e arquivos em modo kernel, ou em espera passiva aguardando pacotes da rede.

Ao combinar /usr/bin/time -v para auditar a memória e o escalonador, o formato -w do curl para decompor a latência de rede em deltas precisos e o strace para confirmar chamadas de sistema, você sai da suposição genérica de que algo está lento e passa a apontar exatamente em qual linha do sistema operacional a lentidão reside.

Perguntas frequentes sobre profiling de comandos e rede no Linux#

Por que a soma de user e sys no time é muito menor que o tempo total real?#

O tempo real (real ou wall-clock time) mede o tempo cronológico transcorrido do início ao fim do processo. Já user e sys somam apenas os períodos em que a CPU esteve ativamente executando instruções para o programa. Se o tempo real for muito superior à soma de CPU, o processo passou a maior parte do ciclo bloqueado em chamadas de sistema síncronas esperando eventos externos, como leitura de disco, respostas de rede (sockets TCP) ou fatias de cgroups.

Qual a diferença entre o comando time do Bash e o /usr/bin/time?#

O time sem caminho é uma palavra-chave reservada do shell (built-in). Ele utiliza temporizadores internos do interpretador e exibe apenas métricas básicas de tempo. O /usr/bin/time é um binário externo do GNU que, quando executado com a flag -v, faz a chamada de sistema wait4() e coleta dados da estrutura struct rusage, fornecendo pico de consumo de memória RAM (ru_maxrss), falhas de página (ru_majflt) e trocas de contexto.

Por que o uso de strace deve ser cauteloso em servidores de produção?#

O strace utiliza a interface ptrace(2) do kernel, interceptando cada chamada de sistema na entrada e na saída. Essa interceptação introduz duas trocas de contexto (context switches) para cada syscall executada pelo processo. Em aplicações com intensa atividade de E/S ou milhares de requisições por segundo, o rastreio pode degradar o throughput em dezenas de vezes.

Como calcular o tempo líquido de processamento remoto do servidor no curl?#

No formato -w do curl, as métricas são acumuladas a partir do início da execução ($t_0$). O tempo líquido gasto exclusivamente pelo servidor de destino para processar a requisição (o TTFB líquido) é obtido subtraindo o tempo pré-transferência do início da transferência: time_starttransfer - time_pretransfer.

O que causa um atraso fixo de 5 segundos no time_namelookup do curl?#

Atrasos consistentes de 5 segundos na resolução de nomes geralmente decorrem do timeout padrão da biblioteca C (glibc) aguardando resposta de registros AAAA (IPv6) ou de servidores DNS secundários inalcançáveis listados em /etc/resolv.conf. Testar com a flag -4 no curl isola se o gargalo é causado por falha na infraestrutura de IPv6.

Veja também

Servidores Por dentro da trincheira: debugando uma quebra em cascata no aaPanel, Python 3.12 e Nginx

Servidores Debugging de baixo nível no CloudLinux: syscalls, LVE e o perigo dos limites ilimitados

Desenvolvimento Como diagnosticar o erro 'no LS client available for routing key' no Linux

Este post está licenciado sob CC BY-NC.