Talvez todo programador conheça as palavras de Kent Beck: "Faça funcionar, faça certo, faça rápido". Primeiro, você precisa fazer o programa funcionar, depois fazê-lo funcionar corretamente e só então você pode prosseguir para a otimização.
O autor do artigo, cuja tradução publicamos, diz que recentemente ele decidiu fazer o perfil de seu projeto de código-fonte aberto, o
Flipt . Ele queria encontrar um código no projeto que pudesse ser otimizado sem esforço e, assim, acelerar o programa. Durante a criação de perfil, ele descobriu alguns problemas inesperados no projeto popular de código aberto que o Flipt usou para organizar o roteamento e o suporte ao middleware. Como resultado, foi possível reduzir a quantidade de memória alocada pelo aplicativo durante a operação em 100 vezes. Isso, por sua vez, levou a uma redução no número de operações de coleta de lixo e melhorou o desempenho geral do projeto. Aqui está como foi.
Alta geração de tráfego
Antes que eu pudesse começar a criar perfis, sabia que primeiro precisava gerar uma grande quantidade de tráfego entrando no aplicativo, o que me ajudaria a ver alguns padrões de seu comportamento. Aqui, encontrei imediatamente um problema, pois não havia nada que usasse o Flipt na produção e obtivesse algum tráfego que me permitisse avaliar o trabalho do projeto sob carga. Como resultado, encontrei uma ótima ferramenta para projetos de teste de carga. Este é
Vegeta . Os autores do projeto dizem que o Vegeta é uma ferramenta HTTP universal para teste de carga. Este projeto nasceu da necessidade de carregar serviços HTTP com um grande número de solicitações chegando a serviços com uma determinada frequência.
O projeto Vegeta acabou sendo exatamente a ferramenta que eu precisava, pois me permitiu criar um fluxo contínuo de solicitações para o aplicativo. Com essas solicitações, você pode "shell" o aplicativo conforme necessário, para descobrir indicadores como alocação / uso de memória na pilha, recursos de goroutines, tempo gasto na coleta de lixo.
Depois de realizar alguns experimentos, fui para a seguinte configuração do lançamento do Vegeta:
echo 'POST http://localhost:8080/api/v1/evaluate' | vegeta attack -rate 1000 -duration 1m -body evaluate.json
Esse comando inicia o
Vegeta no modo de
attack , enviando
solicitações de HTTP HTTP POST
REST API a uma velocidade de 1000 solicitações por segundo (e, reconhecidamente, é uma carga séria) por um minuto. Os dados JSON enviados pelo Flipt não são particularmente importantes. Eles são necessários apenas para a formação correta do corpo da solicitação. Essa solicitação foi recebida pelo servidor Flipt, que poderia executar o procedimento de
verificação da solicitação.
Observe que primeiro decidi testar o
/evaluate Flipt
/evaluate . O fato é que ele executa a maior parte do código que implementa a lógica do projeto e executa cálculos "complexos" do servidor. Eu pensei que analisar os resultados desse endpoint me forneceria os dados mais valiosos sobre áreas do aplicativo que poderiam ser melhoradas.
Medições
Agora que eu tinha uma ferramenta para gerar uma quantidade de tráfego suficientemente grande, precisava encontrar uma maneira de medir o impacto que esse tráfego tinha em um aplicativo em execução. Felizmente, o Go possui um conjunto padrão de ferramentas bastante bom que pode medir o desempenho do programa. É sobre o pacote
pprof .
Não vou entrar em detalhes sobre o uso do pprof. Acho que não farei isso melhor do que Julia Evans, que escreveu
este maravilhoso artigo sobre a criação de perfis de programas Go com o pprof (se você ainda não leu, eu definitivamente recomendo que você dê uma olhada).
Como o roteador HTTP no Flipt é implementado usando
go-chi / chi , não foi difícil habilitar o pprof usando o manipulador intermediário Chi
apropriado .
Então, em uma janela, o Flipt funcionou para mim, e Vegeta, preenchendo os pedidos do Flipt, trabalhou em outra janela. Lancei a terceira janela do terminal para coletar e examinar dados de criação de perfil de heap:
pprof -http=localhost:9090 localhost:8080/debug/pprof/heap
Ele usa a ferramenta pprof do Google, que pode visualizar dados de criação de perfil diretamente no navegador.
Primeiro, verifiquei as
inuse_space e
inuse_space para entender o que está acontecendo no heap. No entanto, não consegui encontrar nada notável. Mas quando eu decidi dar uma olhada nas
alloc_space e
alloc_space , algo me alertou.
Análise dos resultados da criação de perfil ( original )Havia a sensação de que algo chamado
flate.NewWriter alocou
flate.NewWriter MB de memória por um minuto. E isso, a propósito, tem mais de 19 gigabytes! Aqui, obviamente, algo estranho estava acontecendo. Mas o que exatamente? Se você observar atentamente o original do esquema acima, verifica-se que
flate.NewWriter é chamado de
gzip.(*Writer).Write , que, por sua vez, é chamado de
middleware.(*compressResponseWriter).Write . Eu rapidamente percebi que o que estava acontecendo não tinha nada a ver com o código Flipt. O problema estava em algum lugar no código do middleware
Chi usado para compactar respostas da API.
// r.Use(middleware.Compress(gzip.DefaultCompression))
Comentei a linha acima e executei os testes novamente. Como esperado, um grande número de operações de alocação de memória desapareceu.
Antes de começar a encontrar uma solução para esse problema, queria examinar essas operações de alocação de memória do outro lado e entender como elas afetam o desempenho. Em particular, eu estava interessado em seu impacto no tempo que o programa leva para coletar lixo. Lembrei que o Go ainda possui uma ferramenta de
rastreamento que permite analisar programas durante a execução deles e coletar informações sobre eles por determinados períodos de tempo. Os dados coletados pelo rastreamento incluem indicadores importantes como o uso de heap, o número de goroutines sendo executadas, informações sobre solicitações de rede e sistema e, o que foi especialmente valioso para mim, informações sobre o tempo gasto no coletor de lixo.
Para coletar efetivamente informações sobre um programa em execução, eu precisava reduzir o número de solicitações por segundo enviadas ao aplicativo usando o Vegeta, já que o servidor regularmente me dava um
socket: too many open files erros de
socket: too many open files . Supus que isso acontecesse porque o
ulimit estava definido muito baixo no meu computador, mas eu não queria entrar nele então.
Então, reiniciei o Vegeta com este comando:
echo 'POST http://localhost:8080/api/v1/evaluate' | vegeta attack -rate 100 -duration 2m -body evaluate.json
Como resultado, se compararmos isso com o cenário anterior, apenas um décimo dos pedidos foi enviado ao servidor, mas isso foi feito por um longo período de tempo. Isso me permitiu coletar dados de alta qualidade sobre o trabalho do programa.
Em outra janela do terminal, executei este comando:
wget 'http://localhost:8080/debug/pprof/trace?seconds=60' -O profile/trace
Como resultado, eu tinha à minha disposição um arquivo com dados de rastreamento coletados em 60 segundos. Você pode examinar este arquivo usando o seguinte comando:
go tool trace profile/trace
A execução deste comando levou à descoberta das informações coletadas no navegador. Eles foram apresentados em uma forma gráfica conveniente para estudo.
Detalhes sobre o
go tool trace podem ser encontrados
neste bom artigo.
Flipt trace results. Um gráfico em forma de serra da alocação de memória na pilha é claramente visível ( original )Nesse gráfico, é fácil ver que a quantidade de memória alocada no heap tende a crescer rapidamente. Neste caso, após o crescimento deve haver uma queda acentuada. Os locais onde a memória alocada cai são operações de coleta de lixo. Aqui você pode ver as colunas azuis pronunciadas na área de GC, representando o tempo gasto na coleta de lixo.
Agora coletei todas as evidências do “crime” de que preciso e poderia começar a procurar uma solução para o problema de alocar memória.
Resolução de problemas
Para descobrir o motivo pelo qual chamar
flate.NewWriter levou a tantas operações de alocação de memória, eu precisava examinar o código-fonte do
Chi . Para descobrir qual versão do Chi estou usando, executei o seguinte comando:
go list -m all | grep chi github.com/go-chi/chi v3.3.4+incompatible
Tendo alcançado o código-fonte
chi / middleware / compress.go @ v3.3.4 , consegui encontrar o seguinte método:
func encoderDeflate(w http.ResponseWriter, level int) io.Writer { dw, err := flate.NewWriter(w, level) if err != nil { return nil } return dw }
Em pesquisas adicionais, descobri que o método
flate.NewWriter , por meio de um manipulador intermediário, era chamado para cada resposta. Isso correspondia à enorme quantidade de operações de alocação de memória que eu vi anteriormente, carregando a API com mil solicitações por segundo.
Eu não queria me recusar a compactar respostas da API ou procurar um novo roteador HTTP e uma nova biblioteca de suporte ao middleware. Portanto, antes de tudo, decidi descobrir se é possível lidar com o meu problema simplesmente atualizando o Chi.
Eu executei
go get -u -v "github.com/go-chi/chi" , atualizei para o Chi 4.0.2, mas o código do middleware para compactação de dados parecia, como me pareceu, o mesmo de antes. Quando executei os testes novamente, o problema não desapareceu.
Antes de encerrar esse problema, decidi procurar por problemas ou mensagens de relações públicas no repositório Chi que mencionassem algo como "middleware de compressão". Encontrei um PR com o seguinte título: "Reescrevi a biblioteca de compactação do middleware". O autor deste PR disse o seguinte: "Além disso, o sync.Pool é usado para codificadores, que possuem um método Reset (io.Writer), que reduz a carga de memória".
Aqui está! Felizmente, esse PR foi adicionado ao ramo
master , mas como nenhum novo release do Chi foi criado, eu precisava atualizar assim:
go get -u -v "github.com/go-chi/chi@master"
Esta atualização, que me agradou muito, era compatível com versões anteriores, seu uso não exigia alterações no código do meu aplicativo.
Resultados
Executei os testes de carga e o perfil novamente. Isso me permitiu verificar se a atualização do Chi resolveu o problema.
Agora, flate.NewWriter usa um centésimo da quantidade de memória alocada usada anteriormente ( original )Olhando novamente para os resultados do rastreamento, vi que o tamanho do heap agora está crescendo muito mais lentamente. Além disso, o tempo necessário para a coleta de lixo diminuiu.
Adeus - "serra" ( original )Após algum tempo,
atualizei o repositório Flipt, tendo mais confiança do que antes que meu projeto seja capaz de lidar adequadamente com a alta carga.
Sumário
Aqui estão as conclusões que tirei depois que consegui encontrar e corrigir os problemas acima:
- Você não deve confiar na suposição de que as bibliotecas de código aberto (mesmo as populares) foram otimizadas ou que não têm problemas óbvios.
- Um problema inocente pode levar a sérias conseqüências, a manifestações do "efeito dominó", especialmente sob carga pesada.
- Se possível, você deve usar o sync.Pool .
- É útil manter as ferramentas à mão para testar projetos sob carga e criar um perfil deles.
- Vá em Kit de Ferramentas e Código Aberto - Ótimo!
Caros leitores! Como você pesquisa o desempenho de seus projetos Go?
