Estatísticas de consulta

O Spanner fornece tabelas integradas que mantêm várias estatísticas para as consultas e instruções DML que usaram mais CPU, além de todas as consultas agregadas, incluindo consultas de fluxo de alterações.

Disponibilidade

Os dados do SPANNER_SYS estão disponíveis somente por meio de interfaces SQL. Por exemplo:

Outros métodos de leitura única fornecidos pelo Spanner não têm suporte SPANNER_SYS:

Uso de CPU agrupado por consulta

As tabelas a seguir rastreiam as consultas com o maior uso de CPU durante um período específico:

  • SPANNER_SYS.QUERY_STATS_TOP_MINUTE: consultas durante intervalos de 1 minuto
  • SPANNER_SYS.QUERY_STATS_TOP_10MINUTE: consultas em intervalos de 10 minutos
  • SPANNER_SYS.QUERY_STATS_TOP_HOUR: consultas durante intervalos de 1 hora

Essas tabelas têm as seguintes propriedades:

  • Cada uma contém dados para intervalos de tempo não sobrepostos do comprimento que o nome da tabela específica.

  • Os intervalos são baseados em tempos de relógio. Os de 1 minuto terminam no minuto, os de 10 minutos terminam a cada 10 minutos, começando na hora, e os intervalos de 1 hora terminam na hora.

    Por exemplo, às 11:59:30, os intervalos mais recentes disponíveis para as consultas SQL são:

    • 1 minuto: 11:58:00–11:58:59
    • 10 minutos: 11:40:00–11:49:59
    • 1 hora: 10:00:00–10:59:59

  • O Spanner agrupa as estatísticas pelo texto da consulta SQL. Se uma consulta usa parâmetros de consulta, o Spanner agrupa todas as execuções dela em uma linha. Se a consulta usar literais de string, o Spanner só vai agrupar as estatísticas se o texto completo da consulta for idêntico. Quando qualquer texto diferir, cada consulta vai aparecer como uma linha separada. Para a DML em lote, o Spanner normaliza o lote eliminando instruções idênticas consecutivas antes de gerar a impressão digital.

  • Se uma tag de solicitação estiver presente, FPRINT será o hash da tag de solicitação. Caso contrário, é o hash do valor TEXT.

  • Cada linha contém estatísticas para todas as execuções de uma consulta SQL específica para a qual o Spanner captura estatísticas durante o intervalo especificado.

  • Se o Spanner não puder armazenar todas as consultas em execução durante o intervalo, o sistema vai priorizar as consultas com o maior uso de CPU durante o intervalo especificado.

  • As consultas rastreadas incluem aquelas que foram concluídas, falharam ou foram canceladas pelo usuário.

  • Um subconjunto de estatísticas é específico das consultas que foram executadas, mas não foram concluídas:

    • Contagem de execuções e latência média em segundos em todas as consultas que não foram bem-sucedidas.

    • Contagem de execução para consultas que expiraram.

    • Contagem de execuções para consultas que foram canceladas pelo usuário ou falharam devido a problemas de conectividade de rede.

  • Todas as colunas nas tabelas são anuláveis.

Esquema de tabela

Nome da coluna Tipo Descrição
INTERVAL_END TIMESTAMP Fim do intervalo de tempo em que as execuções de consultas incluídas ocorreram.
REQUEST_TAG STRING A tag de solicitação opcional para essa operação de consulta. Para mais informações sobre como usar tags, consulte Solução de problemas com tags de solicitação.
QUERY_TYPE STRING Indica se uma consulta é um PARTITIONED_QUERY ou QUERY. Um PARTITIONED_QUERY é uma consulta com um particionadoToken obtido da API PartitionQuery. Tudo as outras consultas e instruções DML são indicadas por QUERY tipo de consulta. As estatísticas de consulta para DML particionada não são compatíveis.
TEXT STRING Texto de consulta SQL, truncado para aproximadamente 64 KB.

As estatísticas de várias consultas que têm a mesma string de tag são agrupadas em uma única linha com o REQUEST_TAG correspondente a essa string de tag. Somente o texto de uma dessas consultas é mostrado neste campo, truncado para aproximadamente 64 KB. Para a DML em lote, o conjunto de instruções SQL é simplificado em uma única linha, concatenada usando um delimitador de ponto e vírgula. Textos SQL idênticos consecutivos são eliminados antes do truncamento.
TEXT_TRUNCATED BOOL Se o texto da consulta foi truncado ou não.
TEXT_FINGERPRINT INT64 O hash do valor REQUEST_TAG, se presente; Caso contrário, o hash do valor TEXT. Corresponde ao campo query_fingerprint no registro de auditoria
EXECUTION_COUNT INT64 Número de vezes que o Spanner encontrou a consulta durante o intervalo.
AVG_LATENCY_SECONDS FLOAT64 Tempo médio, em segundos, para cada execução de consulta no banco de dados. Essa média exclui o tempo de codificação e transmissão do conjunto de resultados e também a sobrecarga.
AVG_ROWS FLOAT64 Número médio de linhas que a consulta retornou.
AVG_BYTES FLOAT64 Número médio de bytes de dados que a consulta retornou, excluindo a sobrecarga de codificação de transmissão.
AVG_ROWS_SCANNED FLOAT64 Número médio de linhas que a consulta verificou, com exceção dos valores excluídos.
AVG_CPU_SECONDS FLOAT64 Número médio de segundos de tempo de CPU que o Spanner gastou em todas as operações para executar a consulta.
ALL_FAILED_EXECUTION_COUNT INT64 Número de vezes que a consulta falhou durante o intervalo.
ALL_FAILED_AVG_LATENCY_SECONDS FLOAT64 Média de tempo, em segundos, para cada execução de consulta que falhou no banco de dados. Essa média exclui o tempo de codificação e transmissão do conjunto de resultados e também a sobrecarga.
CANCELLED_OR_DISCONNECTED_EXECUTION_COUNT INT64 Número de vezes que a consulta foi cancelada pelo usuário ou falhou devido a uma falha na conexão de rede durante o intervalo.
TIMED_OUT_EXECUTION_COUNT INT64 Número de vezes que a consulta expirou durante o intervalo.
AVG_BYTES_WRITTEN FLOAT64 Número médio de bytes gravados pela instrução.
AVG_ROWS_WRITTEN FLOAT64 Número médio de linhas modificadas pela instrução.
STATEMENT_COUNT INT64 A soma das declarações agregadas a essa entrada. Para consultas regulares e DML, isso é igual à contagem de execuções. Para DML em lote, O Spanner captura o número de instruções no lote.
RUN_IN_RW_TRANSACTION_EXECUTION_COUNT INT64 O número de vezes que a consulta foi executada como parte de uma transação de leitura/gravação. Essa coluna ajuda a determinar se é possível evitar conflitos de bloqueio movendo a consulta para uma transação somente leitura.
LATENCY_DISTRIBUTION ARRAY<STRUCT>

Um histograma do tempo de execução da consulta. Os valores são medidos em segundos.

A matriz contém um único elemento e tem o seguinte tipo:
ARRAY<STRUCT<
  COUNT INT64,
  MEAN FLOAT64,
  SUM_OF_SQUARED_DEVIATION FLOAT64,
  NUM_FINITE_BUCKETS INT64,
  GROWTH_FACTOR FLOAT64,
  SCALE FLOAT64,
  BUCKET_COUNTS ARRAY<INT64>>>
Para mais informações sobre os valores, consulte Distribuição.

Para calcular a latência do percentil da distribuição, use a função SPANNER_SYS.DISTRIBUTION_PERCENTILE(distribution, n FLOAT64), que retorna o percentil n estimado. Para conferir um exemplo relacionado, consulte Encontrar a latência do 99º percentil para consultas.

Para mais informações, consulte Percentis e métricas com valor de distribuição.

AVG_MEMORY_PEAK_USAGE_BYTES FLOAT64

Durante uma execução de consulta distribuída, o pico médio de uso de memória em bytes.

Use essa estatística para identificar quais consultas ou tamanhos de dados de tabelas provavelmente vão encontrar limites de memória.
AVG_MEMORY_USAGE_PERCENTAGE FLOAT64

Durante a execução de uma consulta distribuída, o uso médio de memória necessário (como porcentagem do limite de memória permitido para essa consulta).

Essa estatística só rastreia a memória necessária para que a consulta a serem executados. Alguns operadores usam mais memória de buffer para melhorar o desempenho. A memória de buffer adicional usada fica visível no plano de consulta, mas não é usada para calcular AVG_MEMORY_USAGE_PERCENTAGE, porque é usada para otimização e não é necessária.

Use essa estatística para identificar consultas que estão se aproximando do limite de uso de memória e que correm o risco de falhar se o tamanho dos dados aumentar. Para para reduzir o risco de falha na consulta, consulte Práticas recomendadas de SQL para otimizar essas consultas ou dividi-las em partes que leem menos dados.
AVG_QUERY_PLAN_CREATION_TIME_SECS FLOAT64

O tempo médio de CPU em segundos gasto na compilação de consultas, incluindo do ambiente de execução da consulta.

Se o valor dessa coluna for alto, use consultas parametrizadas.
AVG_FILESYSTEM_DELAY_SECS FLOAT64

O tempo médio que a consulta gasta lendo o sistema de arquivos ou sendo bloqueada na entrada/saída (E/S).

Use essa estatística para identificar a possível alta latência causada pelo arquivo E/S do sistema. Para atenuar, adicione um índice ou adicione uma cláusula STORING (GoogleSQL) ou INCLUDE (PostgreSQL) a um índice atual.
AVG_REMOTE_SERVER_CALLS FLOAT64

O número médio de chamadas de servidor remoto (RPC) concluídas pela consulta.

Use essa estatística para identificar se consultas diferentes que verificam o mesmo número de linhas têm um número muito diferente de RPCs. A consulta com um valor de RPC mais alto pode se beneficiar da adição de um índice ou de uma STORING (GoogleSQL) ou INCLUDE (PostgreSQL) cláusula a um índice existente.
AVG_ROWS_SPOOLED FLOAT64

O número médio de linhas gravadas em um disco temporário (não na memória) pela instrução de consulta.

Use essa estatística para identificar consultas com latência potencialmente alta que consomem muita memória e não podem ser executadas na memória. Para reduzir o problema, altere a ordem de JOIN ou adicione um índice que forneça um SORT obrigatório.

EXECUTION_COUNT, AVG_LATENCY_SECONDS e LATENCY_DISTRIBUTION para consultas com falha incluem consultas que falharam devido a sintaxe incorreta ou encontraram um erro temporário, mas foram bem-sucedidas na nova tentativa.

Agregar estatísticas

Há também tabelas que rastreiam dados agregados para todas as consultas para as quais o Spanner capturou estatísticas em um período específico:

  • SPANNER_SYS.QUERY_STATS_TOTAL_MINUTE: consultas durante intervalos de 1 minuto
  • SPANNER_SYS.QUERY_STATS_TOTAL_10MINUTE: consultas em intervalos de 10 minutos
  • SPANNER_SYS.QUERY_STATS_TOTAL_HOUR: consultas durante intervalos de 1 hora

Essas tabelas têm as seguintes propriedades:

  • Cada uma contém dados para intervalos de tempo não sobrepostos do comprimento que o nome da tabela específica.

  • Os intervalos são baseados em tempos de relógio. Os de 1 minuto terminam no minuto, os de 10 minutos terminam a cada 10 minutos, começando na hora, e os intervalos de 1 hora terminam na hora.

    Por exemplo, às 11:59:30, os intervalos mais recentes disponíveis para as consultas SQL são:

    • 1 minuto: 11:58:00–11:58:59
    • 10 minutos: 11:40:00–11:49:59
    • 1 hora: 10:00:00–10:59:59

  • Cada linha contém estatísticas para todas as consultas executadas no banco de dados durante o intervalo especificado, agregadas juntas. Há apenas uma linha por intervalo de tempo e inclui consultas concluídas, consultas com falha e consultas canceladas pelo usuário.

  • As estatísticas capturadas nas tabelas TOTAL podem incluir consultas que O Spanner não fez capturas nas tabelas TOP.

  • Algumas colunas nessas tabelas são expostas como métricas no Cloud Monitoring. As métricas expostas são:

    • Contagem de execuções de consulta
    • Falhas de consulta
    • Latências de consultas
    • Contagem de linhas retornadas
    • Contagem de linhas verificadas
    • Contagem de bytes retornados
    • Consultar o tempo de CPU

    Para mais informações, consulte Métricas do Spanner.

Esquema de tabela

Nome da coluna Tipo Descrição
INTERVAL_END TIMESTAMP Fim do intervalo de tempo em que as execuções de consultas incluídas ocorreram.
EXECUTION_COUNT INT64 Número de vezes que o Spanner viu a consulta durante o intervalo de tempo.
AVG_LATENCY_SECONDS FLOAT64 Tempo médio, em segundos, para cada execução de consulta no banco de dados. Essa média exclui o tempo de codificação e transmissão do conjunto de resultados e também a sobrecarga.
AVG_ROWS FLOAT64 Número médio de linhas que a consulta retornou.
AVG_BYTES FLOAT64 Número médio de bytes de dados que a consulta retornou, excluindo a sobrecarga de codificação de transmissão.
AVG_ROWS_SCANNED FLOAT64 Número médio de linhas que a consulta verificou, com exceção dos valores excluídos.
AVG_CPU_SECONDS FLOAT64 Número médio de segundos de tempo de CPU que o Spanner gastou em todas as operações para executar a consulta.
ALL_FAILED_EXECUTION_COUNT INT64 Número de vezes que a consulta falhou durante o intervalo.
ALL_FAILED_AVG_LATENCY_SECONDS FLOAT64 Média de tempo, em segundos, para cada execução de consulta que falhou no banco de dados. Essa média exclui o tempo de codificação e transmissão do conjunto de resultados e também a sobrecarga.
CANCELLED_OR_DISCONNECTED_EXECUTION_COUNT INT64 Número de vezes que a consulta foi cancelada pelo usuário ou falhou devido a uma falha na conexão de rede durante o intervalo.
TIMED_OUT_EXECUTION_COUNT INT64 Número de vezes que a consulta expirou durante o intervalo.
AVG_BYTES_WRITTEN FLOAT64 Número médio de bytes gravados pela instrução.
AVG_ROWS_WRITTEN FLOAT64 Número médio de linhas modificadas pela instrução.
RUN_IN_RW_TRANSACTION_EXECUTION_COUNT INT64 O número de vezes que as consultas foram executadas como parte de transações de leitura/gravação. Esta coluna ajuda a determinar se é possível evitar contenções de bloqueio movendo algumas consultas para transações somente leitura.
LATENCY_DISTRIBUTION ARRAY<STRUCT>

Um histograma do tempo de execução das consultas. Os valores são medidos em segundos.

Especifique a matriz da seguinte forma:
ARRAY<STRUCT<
  COUNT INT64,
  MEAN FLOAT64,
  SUM_OF_SQUARED_DEVIATION FLOAT64,
  NUM_FINITE_BUCKETS INT64,
  GROWTH_FACTOR FLOAT64,
  SCALE FLOAT64,
  BUCKET_COUNTS ARRAY<INT64>>>
Para mais informações sobre os valores, consulte Distribuição.

Para calcular a latência do percentil da distribuição, use a função SPANNER_SYS.DISTRIBUTION_PERCENTILE(distribution, n FLOAT64), que retorna o percentil n estimado. Para um exemplo relacionado, consulte Encontrar a latência do 99o percentil das consultas.

Para mais informações, consulte Percentis e métricas com valor de distribuição.

Retenção de dados

No mínimo, o Spanner mantém os dados de cada tabela pelo período a seguir períodos:

  • SPANNER_SYS.QUERY_STATS_TOP_MINUTE e SPANNER_SYS.QUERY_STATS_TOTAL_MINUTE: intervalos que abrangem as seis horas anteriores.

  • SPANNER_SYS.QUERY_STATS_TOP_10MINUTE e SPANNER_SYS.QUERY_STATS_TOTAL_10MINUTE: intervalos abrangendo os quatro dias anteriores.

  • SPANNER_SYS.QUERY_STATS_TOP_HOUR e SPANNER_SYS.QUERY_STATS_TOTAL_HOUR: intervalos que abrangem os últimos 30 dias.

Exemplo de consultas

Nesta seção, há várias instruções SQL de exemplo que recuperam estatísticas de consulta. É possível executar essas instruções SQL usando o bibliotecas de cliente, a A Google Cloud CLI ou a Console do Google Cloud.

Listar as estatísticas básicas de cada consulta em um determinado período

A consulta a seguir retorna os dados brutos para as principais consultas no minuto anterior:

SELECT text,
       request_tag,
       interval_end,
       execution_count,
       avg_latency_seconds,
       avg_rows,
       avg_bytes,
       avg_rows_scanned,
       avg_cpu_seconds
FROM spanner_sys.query_stats_top_minute
ORDER BY interval_end DESC;

Listar as consultas com o maior uso de CPU

A consulta a seguir retorna as consultas com o maior uso de CPU na hora anterior:

SELECT text,
       request_tag,
       execution_count AS count,
       avg_latency_seconds AS latency,
       avg_cpu_seconds AS cpu,
       execution_count * avg_cpu_seconds AS total_cpu
FROM spanner_sys.query_stats_top_hour
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_top_hour)
ORDER BY total_cpu DESC;

Encontrar a contagem total de execuções em um determinado período

A consulta a seguir retorna o número total de consultas executadas no intervalo completo de 1 minuto mais recente:

SELECT interval_end,
       execution_count
FROM spanner_sys.query_stats_total_minute
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_top_minute);

Encontrar a latência média de uma consulta

A consulta a seguir retorna as informações de latência média de uma consulta específica:

SELECT avg_latency_seconds
FROM spanner_sys.query_stats_top_hour
WHERE text LIKE "SELECT x FROM table WHERE x=@foo;";

Encontrar a latência do 99o percentil das consultas

A consulta a seguir retorna o 99º percentil do tempo de execução em consultas executadas nos 10 minutos anteriores:

SELECT interval_end, avg_latency_seconds, SPANNER_SYS.DISTRIBUTION_PERCENTILE(latency_distribution[OFFSET(0)], 99.0)
  AS percentile_latency
FROM spanner_sys.query_stats_total_10minute
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_total_10minute)
ORDER BY interval_end;

A comparação da latência média com a latência do 99º percentil ajuda a identificar possíveis consultas fora da curva com tempos de execução altos.

Encontrar as consultas que verificam a maioria dos dados

É possível usar o número de linhas verificadas por uma consulta como uma medida da quantidade de dados que a consulta verificou. A consulta a seguir retorna o número de linhas verificadas por consultas executadas na hora anterior:

SELECT text,
       execution_count,
       avg_rows_scanned
FROM spanner_sys.query_stats_top_hour
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_top_hour)
ORDER BY avg_rows_scanned DESC;

Encontrar as instruções que gravaram mais dados

Use o número de linhas gravadas (ou bytes gravados) pela DML como uma medida de a quantidade de dados que a consulta modificou. A consulta a seguir retorna o número de linhas gravadas por instruções DML executadas na hora anterior:

SELECT text,
       execution_count,
       avg_rows_written
FROM spanner_sys.query_stats_top_hour
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_top_hour)
ORDER BY avg_rows_written DESC;

Uso total da CPU em todas as consultas

A consulta a seguir retorna o número de horas de CPU usadas na hora anterior:

SELECT (avg_cpu_seconds * execution_count / 60 / 60)
  AS total_cpu_hours
FROM spanner_sys.query_stats_total_hour
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_total_hour);

Listar as consultas que falharam em um determinado período

A consulta a seguir retorna os dados brutos, incluindo a contagem de execução e a latência média das consultas com falha das principais consultas no minuto anterior:

SELECT text,
       request_tag,
       interval_end,
       execution_count,
       all_failed_execution_count,
       all_failed_avg_latency_seconds,
       avg_latency_seconds,
       avg_rows,
       avg_bytes,
       avg_rows_scanned,
       avg_cpu_seconds
FROM spanner_sys.query_stats_top_minute
WHERE all_failed_execution_count > 0
ORDER BY interval_end;

Encontrar a contagem total de erros em um determinado período

A consulta a seguir retorna o número total de consultas que não foram executadas no intervalo de 1 minuto completo mais recente.

SELECT interval_end,
       all_failed_execution_count
FROM spanner_sys.query_stats_total_minute
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_top_minute)
ORDER BY interval_end;

Listar as consultas que têm mais tempo limite

A consulta a seguir retorna as consultas com a contagem de tempo limite mais alta na hora anterior.

SELECT text,
       execution_count AS count,
       timed_out_execution_count AS timeout_count,
       avg_latency_seconds AS latency,
       avg_cpu_seconds AS cpu,
       execution_count * avg_cpu_seconds AS total_cpu
FROM spanner_sys.query_stats_top_hour
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.query_stats_top_hour)
ORDER BY timed_out_execution_count DESC;

Encontrar a latência média de execuções bem-sucedidas e com falha em uma consulta

A consulta a seguir retorna a latência média combinada, a latência média para execuções bem-sucedidas e a latência média para execuções com falha de uma consulta específica.

SELECT avg_latency_seconds AS combined_avg_latency,
       all_failed_avg_latency_seconds AS failed_execution_latency,
       ( avg_latency_seconds * execution_count -
         all_failed_avg_latency_seconds * all_failed_execution_count
       ) / (
       execution_count - all_failed_execution_count ) AS success_execution_latency
FROM   spanner_sys.query_stats_top_hour
WHERE  text LIKE "select x from table where x=@foo;";

Como solucionar problemas de alto uso da CPU ou latência de consulta elevada com estatísticas de consulta

As estatísticas de consulta são úteis quando você precisa investigar o alto uso da CPU no seu no banco de dados do Spanner ou apenas tentando entender o funcionamento formas pesadas de consulta no seu banco de dados. A inspeção de consultas que usam quantidades de recursos de banco de dados oferecem aos usuários do Spanner uma maneira reduzir os custos operacionais e possivelmente melhorar as latências gerais do sistema.

É possível usar o código SQL ou os insights para investigar consultas problemáticas em seu banco de dados. O seguinte mostram como investigar essas consultas usando o código SQL.

Embora o exemplo a seguir se concentre no uso da CPU, etapas semelhantes podem ser seguidas para solucionar problemas de latência elevada das consultas e encontrar as consultas com as taxas latências diferentes. Basta selecionar intervalos e consultas por latência em vez de uso da CPU.

Selecione um período para investigar

Inicie a investigação procurando um horário em que o aplicativo começou a apresentar uso elevado da CPU. Por exemplo, se o problema começou a ocorrer por volta das 17h de 24 de julho de 2020 UTC.

Coletar estatísticas de consulta para o período selecionado

Depois de selecionar um período para iniciar nossa investigação, analisaremos as estatísticas coletadas na tabela QUERY_STATS_TOTAL_10MINUTE desse período. Os resultados dessa consulta podem indicar como a CPU e outras estatísticas de consulta mudaram nesse período.

A consulta a seguir retorna as estatísticas de consulta agregadas de 16:30 a 17:30 UTC, inclusive. Estamos usando ROUND em nossa consulta para restringir o número de casas decimais para fins de exibição.

SELECT interval_end,
       execution_count AS count,
       ROUND(avg_latency_seconds,2) AS latency,
       ROUND(avg_rows,2) AS rows_returned,
       ROUND(avg_bytes,2) AS bytes,
       ROUND(avg_rows_scanned,2) AS rows_scanned,
       ROUND(avg_cpu_seconds,3) AS avg_cpu
FROM spanner_sys.query_stats_total_10minute
WHERE
  interval_end >= "2020-07-24T16:30:00Z"
  AND interval_end <= "2020-07-24T17:30:00Z"
ORDER BY interval_end;

A execução da consulta gerou os resultados a seguir.

interval_end contagem latência rows_returned bytes rows_scanned avg_cpu
2020-07-24T16:30:00Z 6 0,06 5,00 536,00 16,67 0,035
2020-07-24T16:40:00Z 55 0,02 0,22 25,29 0,22 0,004
2020-07-24T16:50:00Z 102 0,02 0,30 33,35 0,30 0,004
2020-07-24T17:00:00Z 154 1.06 4.42 486.33 7792208.12 4.633
2020-07-24T17:10:00Z 94 0,02 1,68 106,84 1,68 0,006
2020-07-24T17:20:00Z 110 0,02 0.38 34,60 0.38 0,005
2020-07-24T17:30:00Z 47 0,02 0.23 24,96 0.23 0,004

Na tabela anterior, vemos que o tempo médio de CPU, a coluna avg_cpu na tabela de resultados, é mais alto nos intervalos destacados que termina em 17:00. Também vemos um número muito maior de linhas verificadas em média. Isso indica que consultas mais caras foram executadas entre 16h50 e 17h. Escolha este intervalo para investigar mais na próxima etapa.

Encontrar as consultas que estão causando alto uso da CPU

Com um intervalo de tempo para investigar o selecionado, agora consultamos a tabela QUERY_STATS_TOP_10MINUTE. Os resultados dessa consulta podem ajudar a indicar quais consultas causam alto uso de CPU.

SELECT text_fingerprint AS fingerprint,
       execution_count AS count,
       ROUND(avg_latency_seconds,2) AS latency,
       ROUND(avg_cpu_seconds,3) AS cpu,
       ROUND(execution_count * avg_cpu_seconds,3) AS total_cpu
FROM spanner_sys.query_stats_top_10MINUTE
WHERE
  interval_end = "2020-07-24T17:00:00Z"
ORDER BY total_cpu DESC;

A execução dessa consulta gera os seguintes resultados.

Impressão digital contagem latência cpu total_cpu
5505124206529314852 30 3.88 17.635 529.039
1697951036096498470 10 4.49 18.388 183.882
2295109096748351518 1 0,33 0,048 0,048
11618299167612903606 1 0,25 0,021 0,021
10302798842433860499 1 0,04 0,006 0,006
123771704548746223 1 0,04 0,006 0,006
4216063638051261350 1 0,04 0,006 0,006
3654744714919476398 1 0,04 0,006 0,006
2999453161628434990 1 0,04 0,006 0,006
823179738756093706 1 0,02 0,005 0,0056

As duas principais consultas, destacadas na tabela de resultados, são outliers em termos de CPU e latência média, bem como o número de execuções e o total de CPU. Investigue a primeira consulta listada nesses resultados.

Comparar execuções de consulta ao longo do tempo

Depois de restringir a investigação, podemos focar nossa atenção na tabela QUERY_STATS_TOP_MINUTE. Ao comparar execuções ao longo do tempo em uma consulta específica, podemos procurar correlações entre o número de linhas ou bytes retornados, ou o número de linhas verificadas e de CPU ou latência elevadas. Um desvio pode indicar não uniformidade nos dados. Um número consistente de linhas verificadas pode indicar a falta de índices apropriados ou uma ordem de mesclagem não ideal.

Investigue a consulta que exibe o maior uso médio de CPU e latência executando a seguinte instrução, que filtra o campo text_fingerprint da consulta.

SELECT interval_end,
       ROUND(avg_latency_seconds,2) AS latency,
       avg_rows AS rows_returned,
       avg_bytes AS bytes_returned,
       avg_rows_scanned AS rows_scanned,
       ROUND(avg_cpu_seconds,3) AS cpu,
FROM spanner_sys.query_stats_top_minute
WHERE text_fingerprint = 5505124206529314852
ORDER BY interval_end DESC;

Executar essa consulta retorna os seguintes resultados.

interval_end latência rows_returned bytes_retornados rows_scanned cpu
2020-07-24T17:00:00Z 4,55 21 2365 30000000 19,255
2020-07-24T16:00:00Z 3,62 21 2365 30000000 17,255
2020-07-24T15:00:00Z 4,37 21 2365 30000000 18,350
2020-07-24T14:00:00Z 4,02 21 2365 30000000 17,748
2020-07-24T13:00:00Z 3.12 21 2365 30000000 16,380
2020-07-24T12:00:00Z 3,45 21 2365 30000000 15,476
2020-07-24T11:00:00Z 4,94 21 2365 30000000 22,611
2020-07-24T10:00:00Z 6,48 21 2365 30000000 21,265
2020-07-24T09:00:00Z 0.23 21 2365 5 0,040
2020-07-24T08:00:00Z 0,04 21 2365 5 0,021
2020-07-24T07:00:00Z 0,09 21 2365 5 0,030

Analisando os resultados anteriores, vemos que o número de linhas verificadas, a CPU usada e a latência mudaram significativamente por volta de 9h. Para entender porque esses números aumentaram tão drasticamente, examinaremos o texto da consulta e veremos se alguma mudança no esquema pode ter afetado a consulta.

Use a consulta a seguir para recuperar o texto da consulta que estamos investigando.

SELECT text,
       text_truncated
FROM spanner_sys.query_stats_top_hour
WHERE text_fingerprint = 5505124206529314852
LIMIT 1;

Isso retorna o resultado a seguir.

text text_truncated
Selecione * de pedidos em que o_custkey = 36901; falso

Analisando o texto retornado, percebemos que a consulta está filtrando em um campo chamado o_custkey. Esta é uma coluna não chave na tabela orders. Durante o processo, havia um índice nessa coluna que era solto por volta das 9h. Isso explica a mudança no custo dessa consulta. Podemos adicionar o índice novamente ou, se a consulta não for executada com frequência, decidir não ter o índice e aceitar o custo de leitura mais alto.

Até o momento, nossa investigação se concentrou nas consultas concluídas e encontramos um motivo pelo qual o banco de dados teve alguma degradação no desempenho. Na próxima etapa, focaremos em consultas com falha ou canceladas e mostraremos como examinar esses dados para ter mais insights.

Investigar consultas com falha

As consultas que não são concluídas ainda consomem recursos antes de expirar, são canceladas ou falham. O Spanner rastreia a contagem de execuções e os recursos consumidos por consultas com falha

Para verificar se as consultas com falha contribuem significativamente para a utilização do sistema, podemos verificar quantas consultas falharam no intervalo de interesse.

SELECT interval_end,
       all_failed_execution_count AS failed_count,
       all_failed_avg_latency_seconds AS latency
FROM spanner_sys.query_stats_total_minute
WHERE
  interval_end >= "2020-07-24T16:50:00Z"
  AND interval_end <= "2020-07-24T17:00:00Z"
ORDER BY interval_end;
interval_end failed_count latência
2020-07-24T16:52:00Z 1 15,211391
2020-07-24T16:53:00Z 3 58,312232

Após uma investigação, podemos procurar consultas com mais probabilidade de falhar usando a consulta a seguir.

SELECT interval_end,
       text_fingerprint,
       execution_count,
       avg_latency_seconds AS avg_latency,
       all_failed_execution_count AS failed_count,
       all_failed_avg_latency_seconds AS failed_latency,
       cancelled_or_disconnected_execution_count AS cancel_count,
       timed_out_execution_count AS to_count
FROM spanner_sys.query_stats_top_minute
WHERE all_failed_execution_count > 0
ORDER BY interval_end;
interval_end text_fingerprint execution_count failed_count cancel_count to_count
2020-07-24T16:52:00Z 5505124206529314852 3 1 1 0
2020-07-24T16:53:00Z 1697951036096498470 2 1 1 0
2020-07-24T16:53:00Z 5505124206529314852 5 2 1 1

Como mostrado na tabela anterior, a consulta com impressão digital 5505124206529314852 falhou várias vezes em intervalos diferentes. Considerando um padrão de falhas como esse, é interessante comparar a latência de execuções bem-sucedidas e malsucedidas.

SELECT interval_end,
       avg_latency_seconds AS combined_avg_latency,
       all_failed_avg_latency_seconds AS failed_execution_latency,
       ( avg_latency_seconds * execution_count -
         all_failed_avg_latency_seconds * all_failed_execution_count
       ) / (
       execution_count - all_failed_execution_count ) AS success_execution_latency
FROM   spanner_sys.query_stats_top_hour
WHERE  text_fingerprint = 5505124206529314852;
interval_end combined_avg_latency failed_execution_latency success_execution_latency
2020-07-24T17:00:00Z 3,880420 13,830709 2,774832

Aplicar as práticas recomendadas

Depois de identificar uma consulta candidata à otimização, podemos analisar o perfil da consulta e tentar otimizar usando as práticas recomendadas de SQL.

A seguir