Solucione os mistérios de desempenho do JavaScript com trabalho forense e de detetive

John McCutchan
John McCutchan

Introdução

Nos últimos anos, os aplicativos da Web foram acelerados consideravelmente. Muitos aplicativos agora são executados com rapidez suficiente para que alguns desenvolvedores se perguntem em voz alta "a Web é rápida o suficiente?". Para alguns aplicativos, talvez seja, mas para os desenvolvedores que trabalham em aplicativos de alto desempenho, sabemos que não é rápido o suficiente. Apesar dos avanços incríveis na tecnologia de máquina virtual do JavaScript, um estudo recente mostrou que os aplicativos do Google passam entre 50% e 70% do tempo no V8. Seu aplicativo tem um tempo finito, e reduzir os ciclos de um sistema significa que outro sistema pode fazer mais. Lembre-se de que os aplicativos executados a 60 fps têm apenas 16 ms por frame, caso contrário, vão apresentar falhas. Leia mais para saber como otimizar o JavaScript e criar perfis de aplicativos JavaScript em uma história da equipe de detetives de performance da V8 que rastreia um problema de desempenho obscuro em Find Your Way to Oz.

Sessão do Google I/O 2013

Apresentei este material no Google I/O 2013. Confira o vídeo abaixo:

Por que a performance é importante?

Os ciclos da CPU são um jogo de soma zero. Fazer com que uma parte do sistema use menos recursos permite que você use mais em outra ou execute de forma mais suave. Executar mais rápido e fazer mais são objetivos concorrentes. Os usuários exigem novos recursos e esperam que o aplicativo funcione melhor. As máquinas virtuais JavaScript continuam ficando mais rápidas, mas isso não é motivo para ignorar problemas de desempenho que você pode corrigir hoje, como muitos desenvolvedores que lidam com problemas de desempenho em seus aplicativos da Web já sabem. Em tempo real, com alta taxa de frames, a pressão para que os aplicativos não tenham engasgos é fundamental. A Insomniac Games produziu um estudo que mostrou que uma frame rate sólida e consistente é importante para o sucesso de um jogo: "Uma frame rate sólida ainda é um sinal de um produto profissional e bem feito". Os desenvolvedores da Web precisam prestar atenção.

Solução de problemas de desempenho

Resolver um problema de desempenho é como resolver um crime. Você precisa examinar cuidadosamente as evidências, verificar as causas suspeitas e testar soluções diferentes. Ao longo do processo, documente suas medições para ter certeza de que você realmente corrigiu o problema. Há pouca diferença entre esse método e a forma como os detetives criminais resolvem um caso. Os detetives examinam evidências, interrogam suspeitos e realizam experimentos na esperança de encontrar a prova definitiva.

V8 CSI: Oz

Os magos incríveis que criaram o Find Your Way to Oz (em inglês) entraram em contato com a equipe do V8 para resolver um problema de desempenho que não conseguiam resolver sozinhos. Às vezes, o Oz congelava, causando instabilidade. Os desenvolvedores da Oz fizeram uma investigação inicial usando o painel Timeline no Chrome DevTools. Ao analisar o uso da memória, eles encontraram o temido gráfico dente de serra. Uma vez por segundo, o coletor de lixo coletava 10 MB de lixo, e as pausas da coleta de lixo correspondiam ao jank. Como na captura de tela da linha do tempo no Chrome DevTools:

Cronograma das DevTools

Os detetives do V8, Jakob e Yang, assumiram o caso. O que aconteceu foi uma longa troca de mensagens entre Jakob e Yang, da equipe do V8 e da equipe do Oz. Reduzi esta conversa aos eventos importantes que ajudaram a rastrear o problema.

Evidência

A primeira etapa é coletar e estudar as evidências iniciais.

Que tipo de aplicativo estamos analisando?

A demonstração do Oz é um aplicativo 3D interativo. Por isso, ele é muito sensível a pausas causadas por coletas de lixo. Lembre-se de que um aplicativo interativo executado a 60 fps tem 16 ms para fazer todo o trabalho do JavaScript e precisa deixar parte desse tempo para o Chrome processar as chamadas de gráficos e renderizar a tela.

O Oz realiza muitas computações aritméticas em valores duplos e faz chamadas frequentes para WebAudio e WebGL.

Que tipo de problema de desempenho estamos enfrentando?

Há pausas, ou seja, quedas de frames, ou instabilidade. Essas pausas estão relacionadas às execuções de coleta de lixo.

Os desenvolvedores estão seguindo as práticas recomendadas?

Sim, os desenvolvedores do Oz são experientes em técnicas de otimização e desempenho de VM JavaScript. Vale ressaltar que os desenvolvedores da Oz estavam usando o CoffeeScript como linguagem de origem e produzindo código JavaScript pelo compilador do CoffeeScript. Isso tornou a investigação mais difícil devido à desconexão entre o código escrito pelos desenvolvedores do Oz e o código consumido pelo V8. O Chrome DevTools agora oferece suporte a mapas de origem, o que facilita esse processo.

Por que o coletor de lixo é executado?

A memória em JavaScript é gerenciada automaticamente pela VM para o desenvolvedor. O V8 usa um sistema de coleta de lixo comum em que a memória é dividida em duas (ou mais) gerações. A geração jovem contém objetos alocados recentemente. Se um objeto sobreviver por tempo suficiente, ele será transferido para a geração antiga.

A geração jovem é coletada com uma frequência muito maior do que a geração antiga. Isso é intencional, porque a coleta de geração jovem é muito mais barata. Geralmente, é seguro presumir que as pausas frequentes de GC são causadas pela coleta de geração jovem.

No V8, o espaço de memória jovem é dividido em dois blocos contíguos de tamanhos iguais. Apenas um desses dois blocos de memória está em uso a qualquer momento e é chamado de espaço para. Enquanto houver memória restante no espaço, a alocação de um novo objeto será barata. Um cursor no espaço para é movido para frente pelo número de bytes necessários para o novo objeto. Isso continua até que o espaço seja esgotado. Nesse ponto, o programa é interrompido e a coleta começa.

Memória jovem do V8

Nesse ponto, os espaços "de" e "para" são trocados. O que era o espaço de destino e agora é o espaço de origem é verificado do início ao fim, e todos os objetos que ainda estão ativos são copiados para o espaço de destino ou promovidos para a pilha de geração antiga. Se você quiser detalhes, sugiro que leia sobre o algoritmo de Cheney.

Intuitivamente, você precisa entender que toda vez que um objeto é alocado implicitamente ou explicitamente (por uma chamada para new, [] ou {}), seu aplicativo se aproxima cada vez mais de uma coleta de lixo e da temida pausa do aplicativo.

É esperado que 10 MB/s de lixo sejam gerados para este aplicativo?

Em resumo, não. O desenvolvedor não está fazendo nada para esperar 10 MB/s de lixo.

Suspeitos

A próxima fase da investigação é determinar possíveis suspeitos e reduzi-los.

Suspeito 1

Chamada de novo durante o frame. Lembre-se de que cada objeto alocado se aproxima cada vez mais de uma pausa do GC. Os aplicativos executados com frame rates altos, em particular, precisam ter zero alocações por frame. Isso geralmente requer um sistema de reciclagem de objetos cuidadosamente pensado e específico para o aplicativo. Os detetives do V8 verificaram com a equipe do Oz e eles não estavam ligando para novos. Na verdade, a equipe do Oz já estava ciente desse requisito e disse: "Isso seria constrangedor". Tire isso da lista.

Suspeito 2

Modificar a "forma" de um objeto fora do construtor. Isso acontece sempre que uma nova propriedade é adicionada a um objeto fora do construtor. Isso cria uma nova classe oculta para o objeto. Quando o código otimizado encontra essa nova classe oculta, uma deopt é acionada, e o código não otimizado é executado até ser classificado como quente e otimizado novamente. Essa variação de desotimização e reotimização vai resultar em instabilidade,mas não está estritamente relacionada à criação excessiva de lixo. Após uma auditoria cuidadosa do código, foi confirmado que as formas dos objetos eram estáticas, e o suspeito 2 foi descartado.

Suspeito 3

Aritmética em código não otimizado. Em um código não otimizado, todas as computações resultam em objetos reais sendo alocados. Por exemplo, este snippet:

var a = p * d;
var b = c + 3;
var c = 3.3 * dt;
point.x = a * b * c;

O resultado é a criação de cinco objetos HeapNumber. Os três primeiros são para as variáveis a, b e c. O quarto é para o valor anônimo (a * b), e o quinto é de #4 * c. O quinto é atribuído a point.x.

O Oz faz milhares dessas operações por frame. Se alguma dessas computações ocorrer em funções que nunca são otimizadas, elas podem ser a causa do lixo. Porque as computações em alocação não otimizada memorizam mesmo para resultados temporários.

Suspeito 4

Armazenar um número de precisão dupla em uma propriedade. Um objeto HeapNumber precisa ser criado para armazenar o número e a propriedade alterada para apontar para esse novo objeto. Alterar a propriedade para apontar para o HeapNumber não vai produzir lixo. No entanto, é possível que haja muitos números de precisão dupla armazenados como propriedades de objeto. O código está cheio de instruções como esta:

sprite.position.x += 0.5 * (dt);

Em um código otimizado, toda vez que um valor recém-calculado é atribuído a x, uma instrução aparentemente inofensiva, um novo objeto HeapNumber é alocado implicitamente, aproximando-nos de uma pausa na coleta de lixo.

Ao usar uma matriz com tipo (ou uma matriz regular que só tem números duplos), você pode evitar esse problema específico, já que o armazenamento para o número de dupla precisão é alocado apenas uma vez, e a mudança repetida do valor não requer a alocação de novo armazenamento.

O suspeito 4 é uma possibilidade.

Análise forense

Nesse ponto, os detetives têm dois possíveis suspeitos: o armazenamento de números de heap como propriedades de objeto e a computação aritmética que ocorre em funções não otimizadas. Era hora de ir ao laboratório e determinar definitivamente qual suspeito era culpado. OBSERVAÇÃO: nesta seção, vou usar uma reprodução do problema encontrado no código-fonte real do Oz. Essa reprodução é de ordens de magnitude menor que o código original, o que facilita a análise.

Experimento 1

Verificação do suspeito 3 (computação aritmética em funções não otimizadas). O mecanismo JavaScript V8 tem um sistema de registro integrado que pode fornecer ótimos insights sobre o que está acontecendo nos bastidores.

Começando com o Chrome não funcionando, iniciando o Chrome com as flags:

--no-sandbox --js-flags="--prof --noprof-lazy --log-timer-events"

e, em seguida, sair completamente do Chrome vai resultar em um arquivo v8.log no diretório atual.

Para interpretar o conteúdo de v8.log, faça o download da mesma versão do v8 que o Chrome está usando (confira em about:version) e crie-o.

Depois de criar o v8, você pode processar o registro usando o processador de tiques:

$ tools/linux-tick-processor /path/to/v8.log

Substitua "mac" ou "windows" por "linux", dependendo da sua plataforma. Essa ferramenta precisa ser executada no diretório de origem de nível superior na v8.

O processador de marcação exibe uma tabela de texto com as funções JavaScript que tiveram mais marcações:

[JavaScript]:
ticks  total  nonlib   name
167   61.2%   61.2%  LazyCompile: *opt demo.js:12
 40   14.7%   14.7%  LazyCompile: unopt demo.js:20
 15    5.5%    5.5%  Stub: KeyedLoadElementStub
 13    4.8%    4.8%  Stub: BinaryOpStub_MUL_Alloc_Number+Smi
  6    2.2%    2.2%  Stub: BinaryOpStub_ADD_OverwriteRight_Number+Number
  4    1.5%    1.5%  Stub: KeyedStoreElementStub
  4    1.5%    1.5%  KeyedLoadIC:  {12}
  2    0.7%    0.7%  KeyedStoreIC:  {13}
  1    0.4%    0.4%  LazyCompile: ~main demo.js:30

O demo.js tem três funções: opt, unopt e main. As funções otimizadas têm um asterisco (*) ao lado dos nomes. Observe que a função opt está otimizada e unopt não está.

Outra ferramenta importante no kit de ferramentas do detetive V8 é o plot-timer-event. Ele pode ser executado assim:

$ tools/plot-timer-event /path/to/v8.log

Depois de ser executado, um arquivo png chamado timer-events.png fica no diretório atual. Ao abrir, você verá algo parecido com isto:

Eventos de timer

Além do gráfico na parte de baixo, os dados são mostrados em linhas. O eixo X é o tempo (ms). O lado esquerdo inclui rótulos para cada linha:

Eventos de timer no eixo Y

A linha V8.Execute tem uma linha vertical preta desenhada em cada marcação de perfil em que o V8 estava executando o código JavaScript. V8.GCScavenger tem uma linha vertical azul desenhada em cada marcação de perfil em que o V8 estava realizando uma coleta de nova geração. O mesmo vale para o restante dos estados do V8.

Uma das linhas mais importantes é o "tipo de código sendo executado". Ele vai ficar verde sempre que o código otimizado estiver sendo executado e uma mistura de vermelho e azul quando o código não otimizado estiver sendo executado. A captura de tela a seguir mostra a transição de um código otimizado para um não otimizado e depois de volta para um código otimizado:

Tipo de código sendo executado

O ideal é que essa linha fique verde sólida, mas isso não acontece imediatamente. Isso significa que seu programa fez a transição para um estado estável otimizado. O código não otimizado sempre vai ser executado mais lentamente do que o otimizado.

Se você chegou a esse ponto, vale a pena notar que é possível trabalhar muito mais rápido refatorando seu aplicativo para que ele possa ser executado no shell de depuração v8: d8. O uso do d8 oferece tempos de iteração mais rápidos com as ferramentas de tick-processor e plot-timer-event. Outro efeito colateral do uso do d8 é que fica mais fácil isolar o problema real, reduzindo a quantidade de ruído presente nos dados.

Analisando o gráfico de eventos do timer do código-fonte do Oz, foi mostrada uma transição de código otimizado para não otimizado e, durante a execução de código não otimizado, muitas coleções de nova geração foram acionadas, semelhante à captura de tela a seguir (o tempo foi removido no meio):

Diagrama de eventos do timer

Se você olhar de perto, vai notar que as linhas pretas que indicam quando o V8 está executando o código JavaScript estão ausentes nos mesmos tempos de marcação do perfil das coleções de nova geração (linhas azuis). Isso demonstra claramente que, enquanto o lixo está sendo coletado, o script é pausado.

Analisando a saída do processador de marcação do código-fonte do Oz, a função principal (updateSprites) não foi otimizada. Em outras palavras, a função em que o programa passou mais tempo também não foi otimizada. Isso indica fortemente que o suspeito 3 é o culpado. A origem de updateSprites continha loops parecidos com estes:

function updateSprites(dt) {
    for (var sprite in sprites) {
        sprite.position.x += 0.5 * dt;
        // 20 more lines of arithmetic computation.
    }
}

Conhecendo o V8, eles reconheceram imediatamente que a estrutura de loop for-i-in às vezes não é otimizada pelo V8. Em outras palavras, se uma função contém uma estrutura de loop for-i-in, ela pode não ser otimizada. Esse é um caso especial hoje e provavelmente vai mudar no futuro. Ou seja, o V8 pode otimizar esse elemento de loop. Como não somos detetives do V8 e não conhecemos o V8 como a palma da nossa mão, como podemos determinar por que o updateSprites não foi otimizado?

Experimento 2

Executar o Chrome com essa flag:

--js-flags="--trace-deopt --trace-opt-verbose"

mostra um registro detalhado de dados de otimização e desotimização. Ao pesquisar os dados para updateSprites, encontramos:

[disabled optimization for updateSprites, reason: ForInStatement is not fast case]

Assim como os detetives suspeitaram, a estrutura de loop for-i-in era o motivo.

Caso encerrado

Depois de descobrir o motivo pelo qual a função updateSprites não foi otimizada, a correção foi simples. Basta mover a computação para a própria função, ou seja:

function updateSprite(sprite, dt) {
    sprite.position.x += 0.5 * dt;
    // 20 more lines of arithmetic computation.
}

function updateSprites(dt) {
    for (var sprite in sprites) {
        updateSprite(sprite, dt);
    }
}

O updateSprite será otimizado, resultando em muito menos objetos HeapNumber, resultando em pausas de GC menos frequentes. Para confirmar isso, basta realizar os mesmos experimentos com um novo código. O leitor atento vai notar que os números duplos ainda estão sendo armazenados como propriedades. Se o perfil indicar que vale a pena, mudar a posição para uma matriz de números duplos ou uma matriz de dados digitados reduziria ainda mais o número de objetos criados.

Epílogo

Os desenvolvedores do Oz não pararam por aí. Com as ferramentas e técnicas compartilhadas pelos detetives do V8, eles conseguiram encontrar outras funções que estavam presas no inferno da desotimização e fatoraram o código de computação em funções de folha otimizadas, resultando em um desempenho ainda melhor.

Comece a resolver alguns crimes de performance.