Estatísticas de consulta

O Cloud Spanner fornece tabelas integradas que mantêm várias estatísticas para as consultas que usaram mais CPU, além de todas as consultas agregadas.

Disponibilidade

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

  • A página Consulta de um banco de dados no Console do Cloud.

  • O comando gcloud spanner databases execute-sql

  • A API executeQuery

Outros métodos de leitura única fornecidos pelo Cloud Spanner não são compatíveis com 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 Cloud Spanner agrupa as estatísticas pelo texto da consulta SQL. Se uma consulta usa parâmetros de consulta, o Cloud Spanner agrupa todas as execuções dela em uma linha. Se a consulta usar literais de string, o Cloud Spanner agrupará as estatísticas somente se o texto completo da consulta for idêntico. Quando qualquer texto diferir, cada consulta aparecerá como uma linha separada.

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

  • Se o Cloud Spanner não puder armazenar todas as consultas em execução durante o intervalo, o sistema priorizará aquelas 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:

    • A contagem de execução e a 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ção para consultas que foram canceladas pelo usuário ou falharam devido a problemas de conectividade de rede.

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.
TEXT STRING Texto de consulta SQL, truncado para aproximadamente 64 KB.
TEXT_TRUNCATED BOOL Se o texto da consulta foi truncado ou não.
TEXT_FINGERPRINT INT64 Hash do texto da consulta.
EXECUTION_COUNT INT64 Número de vezes que o Cloud Spanner viu 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, bem como 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 Cloud Spanner passou 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 Tempo médio, 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, bem como 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 conexão de rede interrompida durante o intervalo.
TIMED_OUT_EXECUTION_COUNT INT64 Número de vezes que a consulta expirou durante o intervalo.

EXECUTION_COUNT e AVG_LATENCY_SECONDS 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 Cloud 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, com falha e consultas canceladas pelo usuário.

  • As estatísticas capturadas nas tabelas TOTAL podem incluir consultas que o Cloud Spanner não capturou nas tabelas TOP.

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 Cloud 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, bem como 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 Cloud Spanner passou 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 Tempo médio, 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, bem como 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 conexão de rede interrompida durante o intervalo.
TIMED_OUT_EXECUTION_COUNT INT64 Número de vezes que a consulta expirou durante o intervalo.

Retenção de dados

O Cloud Spanner mantém dados para cada tabela, no mínimo, pelos períodos a seguir:

  • 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.

Consultas de exemplo

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 as bibliotecas de cliente, a ferramenta de linha de comando gcloud ou o Console do Cloud.

Como listar as estatísticas básicas para cada consulta em um determinado período

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

SELECT text,
       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;

Como 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,
       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;

Como 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);

Como 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;";

Como 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;

Como totalizar o uso 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);

Como 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 para as principais consultas no minuto anterior:

SELECT text,
       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;

Como 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;

Como 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;

Como 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;";

Solução de 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 de CPU no banco de dados do Cloud Spanner ou quando está apenas tentando entender os formatos de consulta com uso intensivo de CPU no banco de dados. A inspeção de consultas que usam quantidades significativas de recursos de banco de dados oferece aos usuários do Cloud Spanner uma maneira potencial de reduzir custos operacionais e possivelmente melhorar latências gerais do sistema. Nas etapas a seguir, mostraremos como usar estatísticas de consulta para investigar o alto uso de CPU no banco de dados.

O exemplo abaixo se concentra no uso da CPU, mas é possível seguir etapas semelhantes para solucionar problemas de latência de consulta elevada e encontrar as consultas com as latências mais altas. Basta selecionar intervalos de tempo e consultas por latência em vez de uso da CPU.

Como selecionar um período a ser investigado

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

Coletando 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 as estatísticas de CPU e outras consultas foram alteradas durante esse 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 produziu os resultados a seguir.

interval_end count latency linhas_retornadas bytes linhas verificadas avg_cpu
24/07/2020T16: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
24/07/2020T26: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
24/07/2020T17:10:00Z 94 0.02 1,68 106,84 1,68 0,006
24/07/2020T17:20:00Z 110 0.02 0.38 34,60 0.38 0,005
24/07/2020T17: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, é maior nos intervalos destacados que terminam às 17h. Também vemos um número muito maior de linhas verificadas em média. Isso indica que as consultas mais caras foram executadas entre 16h50 e 17h. Escolheremos esse intervalo para investigar melhor a próxima etapa.

Encontrar quais consultas estão causando alto uso da CPU

Com um intervalo de tempo para investigar, 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 produz os resultados a seguir.

impressão digital count latency 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édias, bem como número de execuções e total de CPUs. Vamos investigar a primeira consulta listada nesses resultados.

Comparação das execuções de consulta ao longo do tempo

Depois de restringir a investigação, podemos olhar para a tabela QUERY_STATS_TOP_MINUTE. Ao comparar execuções ao longo do tempo para uma consulta específica, podemos identificar correlações entre o número de linhas ou bytes retornados ou o número de linhas verificadas e CPU ou latência elevadas. Um desvio pode indicar falta de uniformidade nos dados. Um número alto de linhas verificadas pode indicar a falta de índices apropriados ou ordem de junção abaixo do ideal.

Para investigar a consulta, veja o uso médio mais alto da CPU e a maior latência. Basta executar a instrução a seguir, que filtra o 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;

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

interval_end latency linhas_retornadas bytes_retornados linhas verificadas cpu
24/07/2020T17:00:00Z 4,55 21 2365 30000000 19,255
24/07/2020T16:00:00Z 3,62 21 2365 30000000 17,255
24/07/2020T15:00:00Z 4,37 21 2365 30000000 18,350
24/07/2020T14:00:00Z 4,02 21 2365 30000000 17,748
24/07/2020T13:00:00Z 3.12 21 2365 30000000 16,380
24/07/2020T12:00:00Z 3,45 21 2365 30000000 15,476
24/07/2020T11:00:00Z 4,94 21 2365 30000000 22,611
24/07/2020T10: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

Ao analisar os resultados anteriores, vemos que o número de linhas verificadas, a CPU usada e a latência mudaram significativamente por volta das 9h. Para entender por que esses números aumentaram tão drasticamente, vamos examinar o texto da consulta e ver se alguma alteração 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 * entre os pedidos em que o_custkey = 36901; falso

Ao examinar o texto da consulta retornado, percebemos que a consulta está filtrando um campo chamado o_custkey. Esta é uma coluna sem chave na tabela orders. Na verdade, havia um índice nessa coluna, que foi descartado por volta das 9h. Isso explica a mudança no custo dessa consulta. Podemos adicionar novamente o índice ou, se a consulta for executada com pouca frequência, decidiremos não ter o índice e aceitar o custo de leitura mais alto.

Até o momento, nossa investigação se concentrou em consultas que foram concluídas e encontramos um motivo pelo qual o banco de dados estava apresentando alguma degradação no desempenho. Na próxima etapa, vamos nos concentrar em consultas com falha ou canceladas e mostrar como examinar esses dados para ter mais insights.

Como 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 Cloud Spanner rastreia a contagem de execução e os recursos consumidos por consultas com falha, juntamente com as bem-sucedidas.

Para verificar se as consultas com falha contribuem significativamente para a utilização do sistema, podemos primeiro verificar quantas consultas falharam no intervalo de tempo 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 falhou_contagem latency
2020-07-24T16:52:00Z 1 15,211391
2020-07-24T16:53:00Z 3 58,312232

A partir da investigação, podemos procurar consultas com maior probabilidade de falhas 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 falhou_contagem cancelar_contagem 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 mostra a tabela anterior, a consulta com impressão digital 5505124206529314852 falhou várias vezes durante diferentes intervalos de tempo. Dado 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 devem ser combinados Falha_execução_latência bem-sucedido
24/07/2020T17:00:00Z 3,880420 13,830709 2,774832

Como aplicar as práticas recomendadas

Depois de identificar uma consulta candidata à otimização, podemos ver o perfil dela e tentar usar as práticas recomendadas de SQL.

A seguir