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 aumentaram consideravelmente a velocidade. Agora, muitos aplicativos são executados tão rápido que alguns desenvolvedores se perguntam em voz alta: "a web é rápida o suficiente?". Para alguns aplicativos isso pode ser, 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 JavaScript, um estudo recente mostrou que os aplicativos do Google passam entre 50% e 70% do tempo no V8. Seu aplicativo tem uma quantidade finita de tempo, eliminando os ciclos de um sistema significa que outro sistema pode fazer mais. Lembre-se, aplicativos executados a 60 fps têm apenas 16 ms por frame ou, caso contrário, instabilidade. Continue lendo para saber mais sobre a otimização de JavaScript e o perfil de aplicativos JavaScript em uma história dos detetives de desempenho da equipe do V8 que rastreiam um problema obscuro de desempenho em Encontre o caminho até Oz.

Sessão do Google I/O 2013

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

Por que o desempenho é importante?

Os ciclos de CPU são um jogo de soma zero. Fazer com que uma parte do sistema use menos permite que você use mais em outra ou funcione de forma mais suave. Geralmente, executar mais rápido e fazer mais são objetivos que competem entre si. Os usuários exigem novos recursos e, ao mesmo tempo, esperam que seu aplicativo seja executado sem problemas. As máquinas virtuais JavaScript estão 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 e com frame rate alto, a pressão para que os aplicativos não tenham instabilidade é fundamental. A Insomniac Games produziu um estudo que mostrou que um frame rate consistente e constante é importante para o sucesso de um jogo: "Um frame rate sólido ainda é um sinal de produto profissional e bem feito". Os desenvolvedores da Web estão atentos.

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. Durante todo o caminho, você deve documentar suas medições para ter certeza de que realmente corrigiu o problema. Há pouca diferença entre esse método e como os detetives criminosos quebram um caso. Os detetives examinam evidências, interrogam suspeitos e fazem experimentos na esperança de encontrar a arma de fumaça.

CSI V8: oz

Os incríveis magos que criam o Encontre seu caminho para Oz se aproximaram da equipe do V8 com um problema de desempenho que não conseguiram resolver sozinhos. De vez em quando, o Oz congelava, causando instabilidade. Os desenvolvedores do Oz fizeram algumas investigações iniciais usando o painel da linha do tempo no Chrome DevTools. Analisando o uso da memória, eles encontraram o temido gráfico de dente de serra. Uma vez por segundo, o coletor de lixo coletava 10 MB de lixo, e as pausas da coleta corresponderam à instabilidade. Semelhante à seguinte captura de tela da linha do tempo no Chrome Devtools:

Linha do tempo do Devtools

Os detetives V8, Jakob e Yang, analisaram o caso. O que aconteceu foi uma longa ida e volta entre Jakob e Yang da equipe V8 e da equipe de Oz. Eu selecionei os acontecimentos importantes para identificar esse problema.

Evidência

O primeiro passo é coletar e estudar as evidências iniciais.

Que tipo de aplicativo estamos analisando?

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

Oz realiza muitos cálculos aritméticos em valores duplos e faz chamadas frequentes para WebAudio e WebGL.

Que tipo de problema de desempenho está ocorrendo?

Estamos vendo pausas, ou seja, quedas de frame (instabilidade). Essas pausas se correlacionam com execuções de coleta de lixo.

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

Sim, os desenvolvedores do Oz são especialistas em técnicas de otimização e desempenho de VMs em JavaScript. Os desenvolvedores de Oz usavam o CoffeeScript como linguagem-fonte e produziam código JavaScript por meio do compilador do CoffeeScript. Isso tornou algumas das investigações mais complicadas devido à desconexão entre o código que está sendo escrito pelos desenvolvedores do Oz e o código sendo consumido pelo V8. O Chrome DevTools agora oferece suporte a mapas de origem, o que facilitaria esse processo.

Por que o coletor de lixo é executado?

A memória no 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) generations. A geração mais jovem detém objetos que foram alocados recentemente. Se um objeto sobreviver por tempo suficiente, ele será movido para a geração antiga.

A geração mais jovem é coletada em uma frequência muito maior do que a geração antiga é coletada. Isso ocorre por design, já que a coleção para jovens é muito mais barata. É seguro supor que as pausas frequentes da GC são causadas pela coleção da geração mais jovem.

No V8, o espaço de memória jovem é dividido em dois blocos de memória contíguos de mesmo tamanho. Apenas um desses dois blocos de memória está em uso em dado momento e é chamado de espaço. Embora ainda haja memória no espaço, alocar um novo objeto é barato. Um cursor no espaço é movido o número de bytes necessários para o novo objeto. Isso continua até que o espaço de destino seja esgotado. Nesse momento, o programa é interrompido e a coleta é iniciada.

Memória jovem do V8

Neste ponto, o espaço e o espaço são trocados. O que era para o espaço e agora é do espaço, é verificado do início ao fim e todos os objetos que ainda estão vivos são copiados para o espaço ou promovidos para o heap da geração antiga. Se quiser mais detalhes, sugiro que você leia sobre o Algoritmo de Champa.

Intuitivamente, você deve entender que cada vez que um objeto é alocado implicitamente ou explicitamente (por meio de uma chamada para novo, [] ou {}), seu aplicativo está se aproximando cada vez mais de uma coleta de lixo e do temido aplicativo pausa.

São esperados 10 MB/s de lixo 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 os possíveis suspeitos e, em seguida, resolvê-los.

Suspeita 1

Chamar novo durante o frame. Lembre-se de que cada objeto alocado aproxima você cada vez mais de uma pausa de GC. Em particular, os aplicativos que executam altas taxas de quadros devem se esforçar para zero alocações por frame. Geralmente, isso requer um sistema de reciclagem de objetos cuidadosamente pensado e específico para o aplicativo. Os detetives V8 verificaram com a equipe de Oz e não estavam chamando de novo. Na verdade, a equipe de Oz já conhecia bem esse requisito e disse: "Seria constrangedor". Raspe este aqui 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 identifica essa nova classe oculta, uma desativação é acionada, e o código não otimizado é executado até que o código seja classificado como quente e otimizado novamente. Essa rotatividade de nova otimizaçã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 do objeto eram estáticas, e, portanto, a suspeita no 2 foi descartada.

Suspeita 3

Aritmético em código não otimizado. No código não otimizado, toda a computação resulta na alocação de objetos reais. Por exemplo, este snippet:

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

Resulta na 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 algum desses cálculos ocorrer em funções que nunca são otimizadas, eles podem ser a causa do lixo. Porque os cálculos em não otimizado alocam memória mesmo para resultados temporários.

Suspeito 4

Armazenamento de 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 HeapNumber não produzirá lixo. No entanto, é possível que muitos números de precisão dupla sejam armazenados como propriedades do objeto. O código está cheio de instruções como estas:

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

No código otimizado, sempre que x recebe um valor recém-calculado, uma instrução aparentemente inofensiva, um novo objeto HeapNumber é alocado implicitamente, o que nos aproxima de uma pausa na coleta de lixo.

Observe que ao usar uma matriz tipada (ou uma matriz regular que só contenha o dobro), você pode evitar esse problema específico por completo, já que o armazenamento do número de dupla precisão é alocado apenas uma vez e alterar repetidamente o valor não exige que um novo armazenamento seja alocado.

A suspeita no 4 é uma possibilidade.

Ciência forense

Neste ponto, os detetives têm duas suspeitas possíveis: armazenar números de heap como propriedades de objeto e computação aritmética ocorrendo dentro de funções não otimizadas. Era hora de ir ao laboratório e determinar definitivamente qual suspeito era culpado. OBSERVAÇÃO: nesta seção, usaremos uma reprodução do problema encontrado no código-fonte de Oz. Essa reprodução tem ordens de magnitude menores do que o código original e, portanto, é mais fácil de raciocinar.

Experiência no 1

Verificação da suspeita no 3 (computação aritmética dentro de funções não otimizadas). O mecanismo V8 JavaScript 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 sendo executado, inicie-o com as sinalizações:

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

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

Para interpretar o conteúdo de v8.log, é necessário fazer o download da mesma versão da v8 que seu Chrome está usando (verifique about:version) e criá-la.

Depois de criar o v8, é possível processar o registro usando o processador de marcação:

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

Substitua o Mac ou o Windows pelo 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 baseada em texto de 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

É possível notar que o demo.js tinha três funções: opt, unopt e main. As funções otimizadas têm um asterisco (*) ao lado dos nomes. A função de otimização é otimizada e a de desativação não é.

Outra ferramenta importante no pacote de ferramentas do detetive V8 é plot-timer-event. Ela pode ser executada da seguinte maneira:

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

Depois de executado, um arquivo png chamado timer-events.png ficará no diretório atual. Abrindo o aplicativo, você verá algo parecido com isto:

Eventos de timer

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

Eixo Y dos eventos de timer

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. O 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 acontece com o restante dos estados do V8.

Uma das linhas mais importantes é o "tipo de código que está sendo executado". Ela ficará verde sempre que o código otimizado estiver em execução e vai misturar vermelho e azul quando o código não otimizado estiver sendo executado. A captura de tela a seguir mostra a transição de otimizado para não otimizado e de volta para o código otimizado:

Tipo de código que está sendo executado

Em condições ideais, mas nunca imediatamente, essa linha ficará verde constante. Isso significa que seu programa passou para um estado estável otimizado. O código não otimizado sempre será mais lento do que o código otimizado.

Se você chegou até aqui, é importante notar que pode trabalhar muito mais rápido refatorando o seu aplicativo para que ele possa ser executado no shell de depuração v8: d8. O uso do d8 proporciona tempos de iteração mais rápidos com as ferramentas de processador de marcação e de evento de temporizador. Outro efeito colateral do uso do d8 é a facilidade de isolar o problema real, reduzindo a quantidade de ruído presente nos dados.

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

Gráfico de eventos de timer

Se você prestar atenção, notará que as linhas pretas indicando quando o V8 está executando o código JavaScript estão faltando exatamente nos mesmos tempos de marcação de perfil que as novas coleções de geração (linhas azuis). Isso demonstra claramente que o script está pausado enquanto o lixo é coletado.

Analisando a saída do processador de marcação no código-fonte de Oz, a função superior (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 a causa é a suspeita no 3. A fonte 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 tão bem quanto sabem, eles reconheceram imediatamente que a construção do loop for-i-in às vezes não era otimizada pelo V8. Em outras palavras, se uma função tiver uma construção de loop for-i-in, ela poderá não ser otimizada. Esse é um caso especial hoje e provavelmente mudará no futuro, ou seja, o V8 poderá otimizar essa construção de loop um dia. Como não somos detetives do V8 e não conhecemos o V8 como se fosse nosso, como podemos determinar por que o updateSprites não foi otimizado?

Experiência no 2

Executar o Chrome com esta flag:

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

exibe um registro detalhado dos dados de otimização e desotimização. Pesquisando os dados de updateSprites, encontramos:

[otimização desativada para updateSprites, motivo: ForInStatement não é um caso rápido]

Assim como os detetives criaram a hipótese, o motivo foi a construção do loop for-i-in.

Caso encerrado

Depois de descobrir o motivo pelo qual o updateSprites não foi otimizado, a correção foi simples. Basta mover o cálculo para uma função própria, 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. Deve ser fácil para você confirmar isso realizando os mesmos experimentos com código novo. O leitor cuidadoso vai perceber que números duplos ainda estão sendo armazenados como propriedades. Se a criação de perfil indicar que vale a pena, alterar a posição para uma matriz de dados duplos ou uma matriz de dados tipada reduziria ainda mais o número de objetos criados.

Epílogo

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

Corra e comece a resolver alguns crimes de desempenho!