No primeiro post da série Logs do PDI vimos como configurar as transformações e jobs do PDI para capturar os logs de processamento e como usá-los para monitorar as execuções. Neste segundo post veremos como usar esses dados para identificar gargalos.
Imagine uma pia, na qual uma torneira despeja água. Se entrar mais água do que a pia consegue escoar, a água vai começar a se acumular. Se nada for feito, o nível de água na pia vai subir, e subir, até transbordar. Há duas formas de se evitar que a água transborde: reduzir a entrada ou aumentar a saída. Em termos mais genéricos, para evitar que a água transborde devemos condicionar a entrada à restrição. A “restrição” é justamente a válvula de escoamento da pia.
A velocidade de uma transformação, medida em linhas por segundo, l/s
, está condicionada à restrição existente na transformação: a velocidade de uma transformação será igual à velocidade do seu passo mais lento. Esse passo mais lento é o gargalo.
Se uma transformação possuir passos de ordenação de linhas, agrupamentos etc., que represam linhas, a velocidade média da transformação perde essa relação direta. Ainda vai haver uma relação entre a velocidade da transformação e a velocidade do seu passo mais lento, apenas não será mais 1 para 1. Mas, para manter o didatismo do post, vamos assumir uma transformação perfeitamente esférica e sem atrito, na qual essa condição vale. ;-)
Para aumentar a velocidade de uma transformação, portanto, devemos aumentar a velocidade do fluxo (em l/s) no gargalo. Quando a velocidade no gargalo tiver subido o bastante, algum outro passo vai ser o responsável por restringir a velocidade da transformação, se transformando no novo gargalo. Removemos esse novo gargalo, aumentando a velocidade da transformação, e outro aparecerá, reiniciando o processo. Eventualmente, chegaremos num ponto de rendimento máximo da transformação, no qual uma nova mudança em qualquer passo não vai resultar em aumento de velocidade da transformação.
Simples, não?
Engarrafamento de Linhas
E como descobrimos gargalos em uma transformação?
Se você estiver rodando-a no Spoon, a interface gráfica do PDI, é muito fácil. O PDI detecta o gargalo, definido por ele como “o passo que recebe mais linhas do que é capaz de processar”, e faz com que o Spoon apresente um pontilhado animado em volta de cada passo identificado como gargalo. Esse monitoramento ocorre em tempo real, e causa efeitos curiosos: em certas situações o gargalo parece “pular” entre dois ou mais passos, e em outras vários passos são marcados como gargalos, simultaneamente. A dinâmica que causa isso está fora do escopo deste post, mas não é difícil de entender se você parar para pensar um pouco.
Para que seu Spoon mostre esse passo na sua transformação você precisa habilitar o checkbox Show bottleneck transformation steps, conforme visto na figura abaixo. Essa janela aparece quando selecionamos o item Options, no menu Tools.
Essa opção é muito boa durante o processo de desenvolvimento, mas o que fazer para transformações que rodamos em produção? É um ambiente diferente – memória diferente, disco diferente, carga (tarefas simultâneas) diferentes! Se bobear até o sistema operacional é diferente! Não dá para rodar uma por uma no Spoon e ficar olhando, esperando encontrar um passo-gargalo.
Você adivinhou: consultamos o log de performance.
Entendendo o Gargalo
Conforme o próprio PDI coloca, um gargalo (ou restrição) é “um passo que recebe mais linhas do que é capaz de processar”. Para entender isso você precisa saber um pouco sobre a estrutura interna de um passo.
Um passo possui, grosso modo, três partes:
- Buffer de entrada: onde são gravadas as linhas que chegam do passo anterior, e onde elas ficam esperando ser processadas;
- Motor do passo: retira uma linha do buffer de entrada, processa e grava o resultado no buffer de saída, repetindo esse processo enquanto o passo anterior estiver mandando linhas;
- Buffer de entrada: onde são gravadas as linhas processadas pelo passo, e onde elas aguardam até o engine do PDI movê-las para o passo seguinte.
Assim, se o motor do passo, o processamento em si, não for rápido o bastante, ele começa a ficar para trás: as linhas começam a se acumular no buffer de entrada. Se, além disso, se o passo seguinte for no mínimo tão rápido quanto o passo atual, as linhas processadas não “esquentam cadeira” no buffer de saída, e vão sendo levadas adiante. Por exemplo, na transformação simples mostrada abaixo, com três passos, o passo do meio é um gargalo:
Note que os buffers do passo do meio, representados pelas caixas de entrada e saída, aparecem vazio na saída e cheio na entrada. Essa é a condição de gargalo, ou de restrição. Se pudermos aumentar (elevar) a vazão dessa restrição, a velocidade da transformação, como um todo, aumentará.
Como vemos isso nos logs? Bom, quando rodamos uma transformação no Spoon, este monta um quadro de métricas dos passos, e atualiza-o conforme a transformação vai sendo executada, conforme as linhas vão sendo processadas.
A coluna input/output, última à direita na imagem anterior, exibe a relação entre a quantidade de linhas presentes no buffer de entrada, aguardando processamento, e quantidade de linhas no buffer de saída, aguardando transporte até o passo seguinte. Sempre que um passo possui mais linhas em sua entradas que em sua saída, ele está “segurando” a transformação. Para encontrarmos os gargalos de uma transformação, então, basta analisarmos os passos dela, em busca de buffers de entrada cheios e buffers de saída vazios (ou com bem menos linhas.)
O log que captura as métricas de cada passo, segundo a segundo, chama-se Performance. Veja como ativá-lo no primeiro post da série. Essa tabela possui as seguintes colunas:
- id_batch
- seq_nr
- logdate
- transname
- stepname
- step_copy
- lines_read
- lines_written
- lines_updated
- lines_input
- lines_output
- lines_rejected
- errors
- input_buffer_rows
- output_buffer_rows
Reparou nas duas últimas? São as que nos interessam.
Não vou montar uma solução pronta, mas mostrar como usar essa tabela para desenhar algo que atenda à sua necessidade – e depois vou mostrar um exemplo do relatório que eu uso para “debugar” transformações em produção.
Precisamos de uma consulta que traga os buffers, por cada passo, por transformação. Além disso, como cada transformação pode ter sido executada várias vezes, precisamos filtrar também por lote (id_batch.) Essa consulta ficaria assim:
SELECT
id_batch,
transname,
stepname,
input_buffer_rows,
output_buffer_rows
FROM transformation_performance
WHERE
id_batch = X AND
transname = 'x'
Filtrando para lote 2080 e transformação Carga da Lista de Clientes PF
, temos:
id_batch |
transname |
stepname |
input_buffer_rows |
output_buffer_rows |
2080 |
Carga da Lista de Clientes PF |
Gera strings aleatórias |
224 |
276 |
2080 |
Carga da Lista de Clientes PF |
Cria CEP, Telefone e Fax |
0 |
0 |
2080 |
Carga da Lista de Clientes PF |
Cria CEP, Telefone e Fax |
0 |
0 |
2080 |
Carga da Lista de Clientes PF |
Lê nomes |
0 |
0 |
2080 |
Carga da Lista de Clientes PF |
Cria as partes de CEP, Telefone e Fax |
0 |
0 |
2080 |
Carga da Lista de Clientes PF |
Muda rnd_telefone/fax para string |
0 |
0 |
2080 |
Carga da Lista de Clientes PF |
Seleciona endereço |
2 |
0 |
2080 |
Carga da Lista de Clientes PF |
Lê sobrenomes |
0 |
61 |
2080 |
Carga da Lista de Clientes PF |
Acerta tamanho das strings |
0 |
0 |
2080 |
Carga da Lista de Clientes PF |
Seleciona sobrenome |
61 |
0 |
2080 |
Carga da Lista de Clientes PF |
Lê lista de enderecos |
0 |
0 |
2080 |
Carga da Lista de Clientes PF |
Seleciona nome |
0 |
0 |
2080 |
Carga da Lista de Clientes PF |
Cria ID do Cliente |
1560 |
225 |
2080 |
Carga da Lista de Clientes PF |
Insere cidade_id |
1 |
3 |
2080 |
Carga da Lista de Clientes PF |
Limpa fluxo |
0 |
0 |
2080 |
Carga da Lista de Clientes PF |
Cria índice do endereço |
276 |
125 |
2080 |
Carga da Lista de Clientes PF |
Gerar linhas |
0 |
2444 |
2080 |
Carga da Lista de Clientes PF |
Cria índices de nome |
147 |
110 |
2080 |
Carga da Lista de Clientes PF |
String operations |
3 |
1 |
2080 |
Carga da Lista de Clientes PF |
Absoluto de rnd_cpf |
110 |
3 |
2080 |
Carga da Lista de Clientes PF |
Grava tabela |
0 |
0 |
2080 |
Carga da Lista de Clientes PF |
Gera strings aleatórias |
1778 |
5755 |
2080 |
Carga da Lista de Clientes PF |
Cria CEP, Telefone e Fax |
0 |
0 |
E aí, consegue dizer se algum destes passos é um gargalo? Nem eu. Vamos melhorar nossa consulta: vamos agrupar por passo, remover o nome da transformação e lote da execução, já que ambos são previamente conhecidos (estão no filtro.) Fica assim:
SELECT
stepname,
sum(input_buffer_rows) as buffer_entrada,
sum(output_buffer_rows) as buffer_saida
FROM transformation_performance
WHERE
id_batch = 2080 AND
transname = 'Carga da Lista de Clientes PF'
GROUP BY
stepname
ORDER BY
stepname
Resultado:
stepname |
buffer_entrada |
buffer_saida |
Absoluto de rnd_cpf |
4289 |
2770 |
Acerta tamanho das strings |
10117 |
10100 |
Cria as partes de CEP, Telefone e Fax |
100 |
10098 |
Cria CEP, Telefone e Fax |
10101 |
20099 |
Cria ID do Cliente |
21021 |
11892 |
Cria índice do endereço |
15660 |
3458 |
Cria índices de nome |
3483 |
4289 |
Gerar linhas |
0 |
21902 |
Gera strings aleatórias |
11889 |
15658 |
Grava tabela |
20281 |
0 |
Insere cidade_id |
202 |
259 |
Lê lista de enderecos |
0 |
0 |
Lê nomes |
0 |
0 |
Lê sobrenomes |
0 |
61 |
Limpa fluxo |
20099 |
20281 |
Muda rnd_telefone/fax para string |
125 |
100 |
Seleciona endereço |
258 |
714 |
Seleciona nome |
714 |
100 |
Seleciona sobrenome |
161 |
125 |
String operations |
2770 |
202 |
Já dá para dizer se alguém é gargalo? Não! Veja, buffer de entrada e buffer de saída são métricas não-aditivas: somá-las ao longo do tempo não dá nenhuma informação sobre o processo. Nem somando-as ao longo dos passos, ou das transformações, nada! No máximo, como métricas não-aditivas, talvez uma média ao longo do tempo possa dar alguma idéia do que está acontecendo.
Mesmo assim, a média não ajudaria. Lembra-se que o monitoramento de gargalo do Spoon ocorre em tempo real? E que os gargalos podem pular de um passo para outro? Só conseguimos identificar um gargalo olhando o comportamento dele ao longo do tempo, momento a momento.
Incluíndo o tempo na consulta, temos:
SELECT
stepname,
logdate,
sum(input_buffer_rows) as buffer_entrada,
sum(output_buffer_rows) as buffer_saida
FROM transformation_performance
WHERE
id_batch = 2080 AND
transname = 'Carga da Lista de Clientes PF'
GROUP BY
stepname,
logdate
ORDER BY
stepname
Vai nos dar a seguinte saída:
stepname |
logdate |
buffer_entrada |
buffer_saida |
Absoluto de rnd_cpf |
2016-02-21 16:34:41 |
110 |
3 |
Absoluto de rnd_cpf |
2016-02-21 16:34:41 |
110 |
3 |
Absoluto de rnd_cpf |
2016-02-21 16:34:42 |
87 |
100 |
Absoluto de rnd_cpf |
2016-02-21 16:34:43 |
4092 |
2667 |
Absoluto de rnd_cpf |
2016-02-21 16:34:44 |
0 |
0 |
Absoluto de rnd_cpf |
2016-02-21 16:34:45 |
0 |
0 |
Absoluto de rnd_cpf |
2016-02-21 16:34:46 |
0 |
0 |
Absoluto de rnd_cpf |
2016-02-21 16:34:46 |
0 |
0 |
Acerta tamanho das strings |
2016-02-21 16:34:41 |
0 |
0 |
Acerta tamanho das strings |
2016-02-21 16:34:42 |
0 |
0 |
Acerta tamanho das strings |
2016-02-21 16:34:43 |
120 |
100 |
Acerta tamanho das strings |
2016-02-21 16:34:44 |
9997 |
10000 |
Acerta tamanho das strings |
2016-02-21 16:34:45 |
0 |
0 |
Acerta tamanho das strings |
2016-02-21 16:34:46 |
0 |
0 |
Acerta tamanho das strings |
2016-02-21 16:34:46 |
0 |
0 |
Cria as partes de CEP, Telefone e Fax |
2016-02-21 16:34:41 |
0 |
0 |
Cria as partes de CEP, Telefone e Fax |
2016-02-21 16:34:42 |
0 |
0 |
Cria as partes de CEP, Telefone e Fax |
2016-02-21 16:34:43 |
100 |
101 |
Cria as partes de CEP, Telefone e Fax |
2016-02-21 16:34:44 |
0 |
9997 |
Cria as partes de CEP, Telefone e Fax |
2016-02-21 16:34:45 |
0 |
0 |
Cria as partes de CEP, Telefone e Fax |
2016-02-21 16:34:46 |
0 |
0 |
Cria as partes de CEP, Telefone e Fax |
2016-02-21 16:34:46 |
0 |
0 |
Cria CEP, Telefone e Fax |
2016-02-21 16:34:41 |
0 |
0 |
Cria CEP, Telefone e Fax |
2016-02-21 16:34:42 |
0 |
0 |
Cria CEP, Telefone e Fax |
2016-02-21 16:34:43 |
101 |
100 |
Cria CEP, Telefone e Fax |
2016-02-21 16:34:44 |
10000 |
10000 |
Cria CEP, Telefone e Fax |
2016-02-21 16:34:45 |
0 |
9999 |
Cria CEP, Telefone e Fax |
2016-02-21 16:34:46 |
0 |
0 |
Agora podemos dizer, se em algum instante, um passo se comportou como um gargalo. Claro que examinar os dados assim é uma bobagem – podemos montar um gráfico com isso.
Relatório de Análise de Fluxos
Juntando essa consulta com os relatórios do primeiro post, montamos um relatório de análise de fluxo de transformações:
Esse relatório traça a velocidade daquele passo em linhas por segundo no gráfico de cima, e o volume de linhas presentes nos buffers, no gráfico de baixo, tudo instante a instante. O que vemos é que esse passo possui uma vazão boa, até, de 20.000 l/s, e que ele nunca esteve em condição de gargalo. Muito pelo contrário: no instante 5 ele teve o seu buffer de saída completamente cheio, sugerindo que o passo seguinte poderia ser um gargalo.
Eis o trecho da transformação que estamos analisando:
Os passos seguintes são um Select Values e um Table Output. Eis os buffers do Select Values:
E os do Table Output:
A-há! Veja ali, do momento 3 ao momento 6, como o buffer de entrada (a linha vermelha) sobe até atingir 10.000 linhas, enquanto o buffer de saída permanece em zero! Esse passo é um gargalo! Ele ficou com o buffer de entrada cheio, que fez com que as linhas “transbordassem” para o passo anterior, o Select Values. Tanto esse Select Values não é um gargalo que os dois buffers sobem e descem juntos. Mais ainda: foi justamente entre os momentos 3 e 6 (comuns a todos os passos, aliás, pois o log de performance captura todo mundo junto) que o buffer de saída do passo Cria CEP, Telefone e Fax saturou, isto é, atingiu seu limite de 10.000 linhas, e começou a se refletir no buffer de entrada, mesmo que por apenas um segundo (cada momento equivale a um segundo nesta escala.)
Conclusão
A partir da consulta mostrada podemos criar um relatório que exibe o estado dos buffers de cada passo momento a momento. Usando a transformação como guia, podemos analisar cada um dos passos em busca do sintoma de restrição de fluxo.
Essa não é a melhor análise, já que nos obriga a olhar um por um. Como você faria essa análise automaticamente? Como deixar para o Report Designer detectar os gargalos de uma transformação?
E apenas para fechar o problema encontrado neste exemplo: um gargalo em um passo que grava dados no banco significa que a rede e o banco é que são os gargalos. Dependendo da influência da rede e do banco na força da restrição, podemos levar o processamento para mais perto (reduzindo o custo da rede) ou melhorar o banco com, por exemplo, discos mais rápidos.
Na próxima semana terminaremos a série com um relatório de genealogia de um processo de ETL.
Até lá!
Novo Lançamento!
Sexta-feira, 11 de março de 2016, será o lançamento do meu novo livro, Autopublicação na Prática. Não deixe de passar por aqui, porque – como sempre – ele será lançado por R$ 0,00!