Google 致力于为黑人社区推动种族平等。查看具体举措
Esta página foi traduzida pela API Cloud Translation.
Switch to English

Compreendendo Systrace

systrace é a principal ferramenta para analisar o desempenho do dispositivo Android. No entanto, é realmente um invólucro em torno de outras ferramentas. É o invólucro do lado do host em torno do atrace , o executável do lado do dispositivo que controla o rastreamento do espaço do usuário e configura o ftrace , e o mecanismo de rastreamento primário no kernel do Linux. O systrace usa atrace para habilitar o rastreio, então lê o buffer ftrace e envolve tudo em um visualizador HTML independente. (Embora os kernels mais recentes tenham suporte para Linux Enhanced Berkeley Packet Filter (eBPF), a documentação a seguir se refere ao kernel 3.18 (sem eFPF), pois é o que foi usado no Pixel / Pixel XL.)

Systrace é propriedade das equipes do Google Android e Google Chrome e é de código aberto como parte do projeto Catapult . Além do systrace, Catapult inclui outros utilitários úteis. Por exemplo, ftrace tem mais recursos do que podem ser ativados diretamente pelo systrace ou atrace e contém algumas funcionalidades avançadas que são críticas para depurar problemas de desempenho. (Esses recursos requerem acesso root e geralmente um novo kernel.)

Running systrace

Ao depurar jitter no Pixel / Pixel XL, comece com o seguinte comando:

./systrace.py sched freq idle am wm gfx view sync binder_driver irq workq input -b 96000

Quando combinado com os pontos de rastreamento adicionais necessários para a GPU e exibir a atividade do pipeline, isso dá a você a capacidade de rastrear da entrada do usuário até o quadro exibido na tela. Defina o tamanho do buffer para algo grande para evitar a perda de eventos (porque, sem um buffer grande, algumas CPUs não contêm eventos após algum ponto no rastreamento).

Ao passar pelo systrace, lembre-se de que todo evento é disparado por algo na CPU .

Como o systrace é construído sobre o ftrace e o ftrace é executado na CPU, algo na CPU deve gravar o buffer do ftrace que registra as alterações de hardware. Isso significa que se você estiver curioso sobre por que uma cerca de exibição mudou de estado, você pode ver o que estava sendo executado na CPU no ponto exato de sua transição (algo em execução na CPU acionou essa alteração no log). Este conceito é a base da análise de desempenho usando o Systrace.

Exemplo: quadro de trabalho

Este exemplo descreve um systrace para um pipeline de IU normal. Para acompanhar o exemplo, baixe o arquivo zip de rastreios (que também inclui outros rastreios mencionados nesta seção), descompacte o arquivo e abra o arquivo systrace_tutorial.html em seu navegador. Esteja avisado que este systrace é um arquivo grande; a menos que você use o systrace em seu trabalho do dia-a-dia, este é provavelmente um traço muito maior com muito mais informações do que você já viu em um único traço antes.

Para uma carga de trabalho consistente e periódica, como TouchLatency, o pipeline de IU contém o seguinte:

  1. EventThread no SurfaceFlinger desperta o thread de IU do aplicativo, sinalizando que é hora de renderizar um novo quadro.
  2. O aplicativo renderiza um quadro em UI thread, RenderThread e hwuiTasks, usando recursos de CPU e GPU. Esta é a maior parte da capacidade gasta para a IU.
  3. O aplicativo envia o quadro renderizado para SurfaceFlinger usando um fichário e, em seguida, SurfaceFlinger vai dormir.
  4. Um segundo EventThread no SurfaceFlinger ativa o SurfaceFlinger para acionar a composição e exibir a saída. Se SurfaceFlinger determinar que não há trabalho a ser feito, ele volta a dormir.
  5. O SurfaceFlinger lida com a composição usando Hardware Composer (HWC) / Hardware Composer 2 (HWC2) ou GL. A composição do HWC / HWC2 é mais rápida e com menor consumo de energia, mas tem limitações dependendo do sistema em um chip (SoC). Isso geralmente leva cerca de 4-6 ms, mas pode se sobrepor à etapa 2 porque os aplicativos Android são sempre armazenados em buffer triplo. (Embora os aplicativos sejam sempre com buffer triplo, pode haver apenas um quadro pendente esperando no SurfaceFlinger, o que o faz parecer idêntico ao buffer duplo.)
  6. SurfaceFlinger despacha a saída final para exibir com um driver do fornecedor e volta a hibernar, aguardando a ativação do EventThread.

Vamos percorrer o quadro começando em 15409 ms:

Pipeline de IU normal com EventThread em execução
Figura 1. Pipeline de IU normal, EventThread em execução

A Figura 1 é um quadro normal cercado por quadros normais, portanto, é um bom ponto de partida para entender como o pipeline de IU funciona. A linha de thread da IU para TouchLatency inclui cores diferentes em momentos diferentes. Barras denotam diferentes estados para o tópico:

  • Cinza . Adormecido.
  • Azul. Executável (pode ser executado, mas o planejador ainda não o escolheu para ser executado).
  • Verde. Executando ativamente (o planejador pensa que está executando).
  • Vermelho. Sono ininterrupto (geralmente dormindo em uma trava no kernel). Pode ser indicativo de carga de E / S. Extremamente útil para depurar problemas de desempenho.
  • Laranja. Suspensão ininterrupta devido à carga de E / S.

Para visualizar o motivo do ininterrupto sleep (disponível no sched_blocked_reason ), selecione a fatia vermelha do ininterruptible sleep.

Enquanto EventThread está em execução, o thread da IU para TouchLatency se torna executável. Para ver o que o despertou, clique na seção azul.

Thread da IU para TouchLatency
Figura 2. UI thread para TouchLatency

A Figura 2 mostra que o encadeamento da IU do TouchLatency foi ativado por tid 6843, que corresponde a EventThread. O thread da IU desperta, renderiza um quadro e o enfileira para que o SurfaceFlinger o consuma.

O thread da IU desperta, renderiza um quadro e o empurra para que o SurfaceFlinger o consuma
Figura 3. O thread de IU desperta, renderiza um quadro e o enfileira para que o SurfaceFlinger consuma

Se a tag binder_driver estiver habilitada em um rastreio, você pode selecionar uma transação de fichário para visualizar informações sobre todos os processos envolvidos nessa transação.

Figura 4. Transação Binder

A Figura 4 mostra que, em 15.423,65 ms Binder: 6832_1 em SurfaceFlinger torna-se executável por causa de tid 9579, que é RenderThread do TouchLatency. Você também pode ver queueBuffer em ambos os lados da transação do fichário.

Durante o queueBuffer no lado do SurfaceFlinger, o número de quadros pendentes do TouchLatency vai de 1 para 2.

Os quadros pendentes vão de 1 a 2
Figura 5. Quadros pendentes vão de 1 a 2

A Figura 5 mostra o buffer triplo, onde há dois quadros concluídos e o aplicativo está prestes a começar a renderizar um terceiro. Isso ocorre porque já eliminamos alguns quadros, então o aplicativo mantém dois quadros pendentes em vez de um para tentar evitar mais quadros perdidos.

Logo depois, o thread principal de SurfaceFlinger é ativado por um segundo EventThread para que possa enviar o quadro pendente mais antigo para o display:

O thread principal de SurfaceFlinger é despertado por um segundo EventThread
Figura 6. O thread principal do SurfaceFlinger é despertado por um segundo EventThread

O SurfaceFlinger primeiro trava o buffer pendente mais antigo, o que faz com que a contagem do buffer pendente diminua de 2 para 1.

O SurfaceFlinger primeiro trava no buffer pendente mais antigo
Figura 7. O SurfaceFlinger primeiro trava no buffer pendente mais antigo

Depois de travar o buffer, SurfaceFlinger configura a composição e envia o quadro final para a exibição. (Algumas dessas seções são ativadas como parte do mdss rastreamento mdss , portanto, podem não estar incluídas em seu SoC.)

SurfaceFlinger configura a composição e envia o quadro final
Figura 8. SurfaceFlinger configura a composição e envia o quadro final

Em seguida, mdss_fb0 desperta na CPU 0. mdss_fb0 é o encadeamento do kernel do pipeline de exibição para a saída de um quadro renderizado para a exibição. Podemos ver mdss_fb0 como sua própria linha no rastreamento (role para baixo para visualizar).

mdss_fb0 desperta na CPU 0
Figura 9. mdss_fb0 desperta na CPU 0

mdss_fb0 acorda, é executado brevemente, entra em hibernação ininterrupta e, em seguida, desperta novamente.

Exemplo: estrutura sem trabalho

Este exemplo descreve um sistema usado para depurar jitter Pixel / Pixel XL. Para seguir o exemplo, baixe o arquivo zip de rastreios (que inclui outros rastreios mencionados nesta seção), descompacte o arquivo e abra o arquivo systrace_tutorial.html em seu navegador.

Quando você abre o systrace, você verá algo assim:

TouchLatency em execução no Pixel XL com a maioria das opções ativadas
Figura 10. TouchLatency em execução no Pixel XL (a maioria das opções ativadas, incluindo pontos de rastreamento mdss e kgsl)

Ao procurar jank, verifique a linha FrameMissed em SurfaceFlinger. FrameMissed é uma melhoria de qualidade de vida fornecida pelo HWC2. Ao visualizar o systrace para outros dispositivos, a linha FrameMissed pode não estar presente se o dispositivo não usar HWC2. Em ambos os casos, FrameMissed está correlacionado com SurfaceFlinger perdendo um de seus tempos de execução extremamente regulares e uma contagem de buffer pendente inalterada para o aplicativo ( com.prefabulated.touchlatency ) em um vsync.

Correlação FrameMissed com SurfaceFlinger
Figura 11. Correlação FrameMissed com SurfaceFlinger

A Figura 11 mostra um quadro perdido em 15598,29 & nbps; ms. O SurfaceFlinger acordou brevemente no intervalo vsync e voltou a dormir sem fazer nenhum trabalho, o que significa que o SurfaceFlinger determinou que não valia a pena tentar enviar um quadro para a tela novamente. Por quê?

Para entender como o pipeline quebrou para este quadro, primeiro analise o exemplo de quadro de trabalho acima para ver como um pipeline de IU normal aparece no systrace. Quando estiver pronto, volte ao quadro perdido e retroceda. Observe que o SurfaceFlinger desperta e imediatamente adormece. Ao visualizar o número de quadros pendentes do TouchLatency, há dois quadros (uma boa pista para ajudar a descobrir o que está acontecendo).

SurfaceFlinger acorda e vai dormir imediatamente
Figura 12. SurfaceFlinger acorda e vai dormir imediatamente

Como temos quadros no SurfaceFlinger, não é um problema do aplicativo. Além disso, o SurfaceFlinger está despertando na hora certa, portanto, não é um problema do SurfaceFlinger. Se SurfaceFlinger e o aplicativo parecerem normais, provavelmente é um problema de driver.

Como os mdss e sync pontos de rastreamento de sync estão habilitados, podemos obter informações sobre as cercas (compartilhadas entre o driver de vídeo e o SurfaceFlinger) que controlam quando os quadros são enviados ao monitor. Essas cercas estão listadas em mdss_fb0_retire , que indica quando um quadro está no visor. Essas cercas são fornecidas como parte da categoria de rastreamento de sync . Quais cercas correspondem a eventos específicos no SurfaceFlinger depende de seu SOC e pilha de drivers, portanto, trabalhe com seu fornecedor de SOC para entender o significado das categorias de cerca em seus rastreamentos.

mdss_fb0_retire cercas
Figura 13. mdss_fb0_retire fences

A Figura 13 mostra um quadro que foi exibido por 33 ms, não 16,7 ms como o esperado. No meio dessa fatia, esse quadro deveria ter sido substituído por um novo, mas não foi. Visualize o quadro anterior e procure por qualquer coisa.

Quadro anterior ao quadro quebrado
Figura 14. Quadro anterior ao quadro quebrado

A Figura 14 mostra 14.482 ms por quadro. O segmento quebrado de dois quadros foi de 33,6 ms, que é aproximadamente o que esperaríamos para dois quadros (renderizamos a 60 Hz, 16,7 ms por quadro, que é próximo). Mas 14.482 ms não chega perto de 16,7 ms, sugerindo que algo está muito errado com o display pipe.

Investigue exatamente onde essa cerca termina para determinar o que a controla.

Investigue o fim da cerca
Figura 15. Investigue o fim da cerca

Uma __vsync_retire_work_handler contém __vsync_retire_work_handler , que está em execução quando a cerca muda. Olhando o código-fonte do kernel, você pode ver que faz parte do driver de vídeo. Parece estar no caminho crítico para o pipeline de exibição, portanto, deve ser executado o mais rápido possível. É executável por cerca de 70 nós (não é um longo atraso de programação), mas é uma fila de trabalho e pode não ser programado com precisão.

Verifique o quadro anterior para determinar se isso contribuiu; às vezes, o jitter pode aumentar com o tempo e, eventualmente, causar um prazo perdido.

Quadro anterior
Figura 16. Quadro anterior

A linha executável no kworker não é visível porque o visualizador a torna branca quando é selecionada, mas as estatísticas contam a história: 2,3 ms de atraso do agendador para parte do caminho crítico do pipeline de exibição é ruim . Antes de continuar, corrija o atraso movendo esta parte do caminho crítico do pipeline de exibição de uma fila de trabalho (que é executada como um SCHED_OTHER CFS) para um SCHED_FIFO SCHED_FIFO dedicado. Essa função precisa de garantias de tempo que as filas de trabalho não podem (e não têm a intenção de) fornecer.

É esse o motivo do tranco? É difícil dizer de forma conclusiva. Fora dos casos fáceis de diagnosticar, como contenção de bloqueio do kernel que faz com que os threads críticos de exibição fiquem suspensos, os rastreamentos geralmente não especificam o problema. Será que esse tremor pode ter sido a causa do quadro perdido? Absolutamente. Os tempos de fence devem ser 16,7 ms, mas eles não são nem um pouco próximos disso nos frames que levam ao frame removido. Dado o quão fortemente acoplado é o pipeline de exibição, é possível que o tremor em torno dos tempos da cerca resultou em uma moldura perdida.

Neste exemplo, a solução envolveu a conversão de __vsync_retire_work_handler de uma __vsync_retire_work_handler de trabalho em um kthread dedicado. Isso resultou em melhorias perceptíveis no jitter e na redução do jank no teste de bola quicando. Os rastreamentos subsequentes mostram intervalos de cerca que oscilam muito perto de 16,7 ms.