Esta página foi traduzida pela API Cloud Translation.

Estatísticas de transação

O Spanner tem tabelas integradas que armazenam estatísticas sobre transações. É possível recuperar estatísticas dessas tabelas SPANNER_SYS.TXN_STATS* usando instruções SQL.

Quando usar estatísticas de transação

As estatísticas de transação são úteis ao investigar problemas de desempenho. Por exemplo, é possível verificar se há transações de execução lenta que podem estar afetando o desempenho ou as consultas por segundo (QPS, na sigla em inglês) no banco de dados. Outro cenário é quando os aplicativos cliente estão com alta latência de execução de transações. A análise das estatísticas de transações pode ajudar a descobrir possíveis gargalos, como grandes volumes de atualizações em uma coluna específica, o que pode estar afetando a latência.

Disponibilidade

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

A página do Spanner Studio de um banco de dados no console do Google Cloud
O comando gcloud spanner databases execute-sql
Painel Insights da transação
A API executeQuery

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

Estatísticas de latência agrupadas por transação

As tabelas a seguir rastreiam as estatísticas de transações TOP com consumo intensivo de recursos durante um período específico.

SPANNER_SYS.TXN_STATS_TOP_MINUTE: estatísticas de transação agregadas em intervalos de 1 minuto.
SPANNER_SYS.TXN_STATS_TOP_10MINUTE: estatísticas de transação agregadas em intervalos de 10 minutos.
SPANNER_SYS.TXN_STATS_TOP_HOUR: estatísticas de transação agregadas em 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 por FPRINT (impressão digital) do transações. Se uma tag de transação estiver presente, FPRINT é o hash da tag. Caso contrário, é o hash calculada com base nas operações envolvidas na transação.
Como as estatísticas são agrupadas com base em FPRINT, se a mesma transação for executada várias vezes em qualquer intervalo de tempo, ainda veremos apenas uma entrada para a transação em questão nessas tabelas.
Cada linha contém estatísticas para todas as execuções de uma transação específica. para o qual o Spanner captura estatísticas durante o intervalo especificado.
Se o Spanner não conseguir armazenar as estatísticas de todas as transações executadas durante intervalo nessas tabelas, o sistema prioriza transações com o maior latência, tentativas de confirmação e bytes gravados durante o período intervalo.
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 transação incluídas ocorreram.
`TRANSACTION_TAG`	`STRING`	Tag opcional da transação para esta operação de transação. Para mais informações sobre o uso de tags, consulte Solução de problemas com tags de transação. As estatísticas de várias transações que têm a mesma string de tag são agrupadas em uma única linha com "TRANSACTION_TAG" correspondente a essa string de tag.
`FPRINT`	`INT64`	Hash de `TRANSACTION_TAG`, se houver. Caso contrário, o hash será calculado com base nas operações envolvidas na transação. Juntos, `INTERVAL_END` e `FPRINT` atuam como uma chave exclusiva para essas tabelas.
`READ_COLUMNS`	`ARRAY<STRING>`	O conjunto de colunas que foram lidas pela transação.
`WRITE_CONSTRUCTIVE_COLUMNS`	`ARRAY<STRING>`	O conjunto de colunas que foram gravadas construtivamente (ou seja, atribuídas a novos valores) pela transação. Para fluxo de alterações, se a transação envolve gravações em colunas e tabelas monitoradas por um fluxo de alterações, `WRITE_CONSTRUCTIVE_COLUMNS` conterá duas colunas: `.data` e `._exists` ¹, prefixado com um nome de fluxo de alterações.
`WRITE_DELETE_TABLES`	`ARRAY<STRING>`	O conjunto de tabelas que tiveram linhas excluídas ou substituídas pela transação.
`ATTEMPT_COUNT`	`INT64`	O número total de vezes que ocorre uma tentativa de transação, incluindo de tentativas que são canceladas antes de chamar `commit`.
`COMMIT_ATTEMPT_COUNT`	`INT64`	Número total de tentativas de confirmação de transação. Precisa corresponder ao número de chamadas para o método `commit` da transação.
`COMMIT_ABORT_COUNT`	`INT64`	O número total de tentativas de transação canceladas, incluindo aquelas que foram canceladas antes de chamar o método `commit` da transação .
`COMMIT_RETRY_COUNT`	`INT64`	Número total de tentativas canceladas anteriormente de tentativas. Uma transação do Spanner pode ser tentada várias vezes antes da confirmação devido a contenções de bloqueio ou eventos temporários. Uma alta o número de novas tentativas em relação às tentativas de confirmação indica que pode haver que vale a pena investigar. Para mais informações, consulte Noções básicas sobre transações e contagens de confirmações nesta página.
`COMMIT_FAILED_PRECONDITION_COUNT`	`INT64`	Número total de tentativas de confirmação de transação que retornaram uma pré-condição com falha erros, como `UNIQUE` violações de índice, linha já existe, linha não encontrada, e assim por diante.
`AVG_PARTICIPANTS`	`FLOAT64`	Número médio de participantes em cada tentativa de confirmação. Para saber mais sobre os participantes, consulte Vida de Leituras e leituras do Spanner Gravações.
`AVG_TOTAL_LATENCY_SECONDS`	`FLOAT64`	Média de segundos tomada da primeira operação da transação a ser confirmada/cancelada.
`AVG_COMMIT_LATENCY_SECONDS`	`FLOAT64`	Média de segundos usados para executar a operação de confirmação.
`AVG_BYTES`	`FLOAT64`	Número médio de bytes gravados pela transação.
`TOTAL_LATENCY_DISTRIBUTION`	`ARRAY<STRUCT>`	Um histograma da latência total de confirmação, que é o tempo do horário de início da primeira operação transacional para o commit ou abortar horário, para todas as tentativas de uma transação. Observação sobre a interface PostgreSQL: Os bancos de dados do dialeto PostgreSQL não são compatíveis com esta coluna. Se uma transação for cancelada várias vezes e realiza a confirmação, a latência é medida para cada até a confirmação final bem-sucedida. Os valores são medidos em segundos. A matriz contém um único elemento e tem o seguinte tipo: e `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 o percentil de latência desejado da distribuição, use a função `SPANNER_SYS.DISTRIBUTION_PERCENTILE(distribution, n FLOAT64)`, que retorna o no percentil estimado. Para um exemplo relacionado, consulte Encontrar a latência do 99o percentil para transações. Para mais informações, consulte Percentis e métricas com valor de distribuição.
`OPERATIONS_BY_TABLE`	`ARRAY<STRUCT>`	Impacto das operações `INSERT` ou `UPDATE` pelo transação por tabela. Isso é indicado pelo número de vezes que as linhas são afetadas e o número de bytes gravados. Observação sobre a interface PostgreSQL: Os bancos de dados do dialeto PostgreSQL não são compatíveis com esta coluna. Essa coluna ajuda a visualizar a carga nas tabelas e fornece insights na taxa em que uma transação grava em tabelas. Especifique a matriz da seguinte forma: e `ARRAY<STRUCT< TABLE STRING(MAX), INSERT_OR_UPDATE_COUNT INT64, INSERT_OR_UPDATE_BYTES INT64>>`

¹ _exists é um campo interno usado para verificar se uma determinada linha existe ou não.

Exemplo de consultas

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

Listar as estatísticas básicas de cada transação em um determinado período

A consulta a seguir retorna os dados brutos das principais transações no minuto anterior.

SELECT fprint,
       read_columns,
       write_constructive_columns,
       write_delete_tables,
       avg_total_latency_seconds,
       avg_commit_latency_seconds,
       operations_by_table,
       avg_bytes
FROM spanner_sys.txn_stats_top_minute
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.txn_stats_top_minute);

Saída da consulta

fprint	read_columns	write_constructive_columns	write_delete_tables	avg_total_latency_seconds	avg_commit_latency_seconds	operations_by_table	avg_bytes
`40015598317`	`[]`	`["Routes.name", "Cars.model"]`	`["Users"]`	`0.006578737`	`0.006547737`	`[["Cars",1107,30996],["Routes",560,26880]]`	`25286`
`20524969030`	`["id", "no"]`	`[]`	`[]`	`0.001732442`	`0.000247442`	`[]`	`0`
`77848338483`	`[]`	`[]`	`["Cars", "Routes"]`	`0.033467418`	`0.000251418`	`[]`	`0`

Listar as transações com a maior latência média de confirmação

A consulta a seguir retorna as transações com alta latência média de confirmação na hora anterior, ordenadas da latência média mais alta para a mais baixa.

SELECT fprint,
       read_columns,
       write_constructive_columns,
       write_delete_tables,
       avg_total_latency_seconds,
       avg_commit_latency_seconds,
       avg_bytes
FROM spanner_sys.txn_stats_top_hour
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.txn_stats_top_hour)
ORDER BY avg_commit_latency_seconds DESC;

Saída da consulta

fprint	read_columns	write_constructive_columns	write_delete_tables	avg_total_latency_seconds	avg_commit_latency_seconds	avg_bytes
`40015598317`	`[]`	`["Routes.name", "Cars.model"]`	`["Users"]`	`0.006578737`	`0.006547737`	`25286`
`77848338483`	`[]`	`[]`	`["Cars", "Routes"]`	`0.033467418`	`0.000251418`	`0`
`20524969030`	`["id", "no"]`	`[]`	`[]`	`0.001732442`	`0.000247442`	`0`

Encontrar a latência média de transações que leem determinadas colunas

A consulta a seguir retorna as informações de latência média das transações que leem a coluna ADDRESS das estatísticas de 1 hora:

SELECT fprint,
       read_columns,
       write_constructive_columns,
       write_delete_tables,
       avg_total_latency_seconds
FROM spanner_sys.txn_stats_top_hour
WHERE 'ADDRESS' IN UNNEST(read_columns)
ORDER BY avg_total_latency_seconds DESC;

Saída da consulta

fprint	read_columns	write_constructive_columns	write_delete_tables	avg_total_latency_seconds
`77848338483`	`["ID", "ADDRESS"]`	`[]`	`["Cars", "Routes"]`	`0.033467418`
`40015598317`	`["ID", "NAME", "ADDRESS"]`	`[]`	`["Users"]`	`0.006578737`

Listar transações pelo número médio de bytes modificados

A consulta a seguir retorna as transações de amostra na última hora, ordenadas pelo número médio de bytes modificados pela transação.

SELECT fprint,
       read_columns,
       write_constructive_columns,
       write_delete_tables,
       avg_bytes
FROM spanner_sys.txn_stats_top_hour
ORDER BY avg_bytes DESC;

Saída da consulta

fprint	read_columns	write_constructive_columns	write_delete_tables	avg_bytes
`40015598317`	`[]`	`[]`	`["Users"]`	`25286`
`77848338483`	`[]`	`[]`	`["Cars", "Routes"]`	`12005`
`20524969030`	`["ID", "ADDRESS"]`	`[]`	`["Users"]`	`10923`

Agregar estatísticas

SPANNER_SYS também contém tabelas para armazenar dados agregados de todas as transações de quais o Spanner capturou estatísticas em um período específico:

SPANNER_SYS.TXN_STATS_TOTAL_MINUTE: agregar estatísticas de todas as transações durante intervalos de 1 minuto
SPANNER_SYS.TXN_STATS_TOTAL_10MINUTE: agregar estatísticas de todas as transações durante intervalos de 10 minutos
SPANNER_SYS.TXN_STATS_TOTAL_HOUR: agregar estatísticas de todas as transações durante intervalos de 1 hora

As tabelas de estatísticas agregadas 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 11h59m30s, os intervalos mais recentes disponíveis para consultas SQL em estatísticas de transação agregadas 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 de todas as transações agregadas executadas no banco de dados durante o intervalo especificado. Há apenas uma linha por intervalo de tempo.
As estatísticas capturadas nas tabelas SPANNER_SYS.TXN_STATS_TOTAL_* podem incluem transações que o Spanner não capturou SPANNER_SYS.TXN_STATS_TOP_* tabelas.
Algumas colunas nessas tabelas são expostas como métricas no Cloud Monitoring. As métricas expostas são:
- Contagem de tentativas de confirmação
- Contagem de novas tentativas de confirmação
- Participantes da transação
- Latências de transações
- Bytes gravados
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 essa estatística foi capturada.
`ATTEMPT_COUNT`	`INT64`	O número total de vezes que as transações são tentadas, incluindo o de tentativas que são canceladas antes de chamar `commit`.
`COMMIT_ATTEMPT_COUNT`	`INT64`	Número total de tentativas de confirmação de transação. Precisa corresponder ao número de chamadas para o método `commit` da transação.
`COMMIT_ABORT_COUNT`	`INT64`	O número total de tentativas de transação canceladas, incluindo aquelas que são canceladas antes de chamar o método `commit` da transação .
`COMMIT_RETRY_COUNT`	`INT64`	Número de tentativas de confirmação que são tentativas anteriores de serem canceladas. Uma transação do Spanner pode ter sido tentada várias vezes antes da confirmação devido a contenções de bloqueio ou eventos temporários. Uma alta o número de novas tentativas em relação às tentativas de confirmação indica que pode haver que vale a pena investigar. Para mais informações, consulte Noções básicas sobre transações e contagens de confirmações nesta página.
`COMMIT_FAILED_PRECONDITION_COUNT`	`INT64`	Número total de tentativas de confirmação de transação que retornaram uma pré-condição com falha erros, como `UNIQUE` violações de índice, linha já existe, linha não encontrada, e assim por diante.
`AVG_PARTICIPANTS`	`FLOAT64`	Número médio de participantes em cada tentativa de confirmação. Para saber mais sobre os participantes, consulte Vida de Leituras e leituras do Spanner Gravações.
`AVG_TOTAL_LATENCY_SECONDS`	`FLOAT64`	Média de segundos tomada da primeira operação da transação a ser confirmada/cancelada.
`AVG_COMMIT_LATENCY_SECONDS`	`FLOAT64`	Média de segundos usados para executar a operação de confirmação.
`AVG_BYTES`	`FLOAT64`	Número médio de bytes gravados pela transação.
`TOTAL_LATENCY_DISTRIBUTION`	`ARRAY<STRUCT>`	Um histograma da latência total de confirmação, que é o tempo do horário de início da primeira operação transacional para o horário de confirmação ou cancelamento para todas as tentativas de transação. Observação sobre a interface PostgreSQL: Os bancos de dados do dialeto PostgreSQL não são compatíveis com esta coluna. Se uma transação cancelar várias vezes e, em seguida, realiza a confirmação, a latência é medida para cada tentativa até a confirmação final. Os valores são medidos em segundos. A matriz contém um único elemento e tem o seguinte tipo: e `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 o percentil de latência desejado da distribuição, use a função `SPANNER_SYS.DISTRIBUTION_PERCENTILE(distribution, n FLOAT64)`, que retorna o no percentil estimado. Para conferir um exemplo, consulte Encontrar o 99o percentil latência para transações. Para mais informações, consulte Percentis e métricas com valor de distribuição.
`OPERATIONS_BY_TABLE`	`ARRAY<STRUCT>`	Impacto das operações `INSERT` ou `UPDATE` para todos transações por tabela. Isso é indicado pelo número vezes que as linhas são afetadas e o número de bytes gravados. Observação sobre a interface PostgreSQL: Os bancos de dados do dialeto PostgreSQL não são compatíveis com esta coluna. Essa coluna ajuda a visualizar a carga nas tabelas e fornece insights sobre a taxa de gravação das transações nas tabelas. Especifique a matriz da seguinte forma: e `ARRAY<STRUCT< TABLE STRING(MAX), INSERT_OR_UPDATE_COUNT INT64, INSERT_OR_UPDATE_BYTES INT64>>`

Exemplo de consultas

Encontrar o número total de tentativas de confirmação para todas as transações

A consulta a seguir retorna o número total de tentativas de confirmação para todas as transações no intervalo completo de 1 minuto mais recente:

SELECT interval_end,
       commit_attempt_count
FROM spanner_sys.txn_stats_total_minute
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.txn_stats_total_minute)
ORDER BY interval_end;

Saída da consulta

interval_end	commit_attempt_count
`2020-01-17 11:46:00-08:00`	`21`

Há apenas uma linha no resultado porque as estatísticas agregadas têm apenas uma entrada por interval_end para qualquer duração.

Encontrar a latência total de confirmação em todas as transações

A consulta a seguir retorna a latência total de confirmação em todas as transações nos últimos 10 minutos:

SELECT (avg_commit_latency_seconds * commit_attempt_count / 60 / 60)
  AS total_commit_latency_hours
FROM spanner_sys.txn_stats_total_10minute
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.txn_stats_total_10minute);

Saída da consulta

total_commit_latency_hours
`0.8967`

Há apenas uma linha no resultado porque as estatísticas agregadas têm apenas uma entrada por interval_end para qualquer duração.

Encontrar a latência do 99o percentil para transações

A consulta a seguir retorna a latência do 99o percentil das transações executadas em nos últimos 10 minutos:

SELECT interval_end, avg_total_latency_seconds,
       SPANNER_SYS.DISTRIBUTION_PERCENTILE(total_latency_distribution[OFFSET(0)], 99.0)
  AS percentile_latency
FROM spanner_sys.txn_stats_total_10minute
WHERE interval_end =
  (SELECT MAX(interval_end)
   FROM spanner_sys.txn_stats_total_10minute)
ORDER BY interval_end;

Saída da consulta

interval_end	avg_total_latency_seconds	percentile_latency
`2022-08-17 11:46:00-08:00`	`0.34576998305986395`	`9.00296190476190476`

Observe a grande diferença entre a latência média e a do 99o percentil. A latência do 99o percentil ajuda a identificar possíveis transações atípicas com latência alta.

Há apenas uma linha no resultado porque as estatísticas agregadas têm somente uma entrada por interval_end para qualquer período.

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.TXN_STATS_TOP_MINUTE e SPANNER_SYS.TXN_STATS_TOTAL_MINUTE: intervalos que abrangem as seis horas anteriores.
SPANNER_SYS.TXN_STATS_TOP_10MINUTE e SPANNER_SYS.TXN_STATS_TOTAL_10MINUTE: intervalos abrangendo os quatro dias anteriores.
SPANNER_SYS.TXN_STATS_TOP_HOUR e SPANNER_SYS.TXN_STATS_TOTAL_HOUR: intervalos que abrangem os últimos 30 dias.

As estatísticas de transação no Spanner oferecem insights sobre como um aplicativo está usando o banco de dados e são úteis na investigação de problemas de desempenho. Por exemplo, é possível verificar se há transações de execução lenta que possam estar causando contenção ou identificar possíveis origens de alta carga, como grandes volumes de atualizações em uma coluna específica. Usando as etapas a seguir, mostraremos como usar as estatísticas de transação para investigar contenções no seu banco de dados.

Entender transações e contagens de confirmações

Uma transação do Spanner pode ter que ser testada várias vezes antes commits. Isso geralmente ocorre quando duas transações tentam trabalhar nos mesmos dados ao mesmo tempo, e uma das transações precisa ser cancelada para preservar a propriedade de isolamento de transação. Outros eventos transitórios que também podem cancelar uma transação incluem:

Problemas temporários de rede.
Alterações no esquema do banco de dados que estão sendo aplicadas enquanto uma transação está em processo de confirmação.
A instância do Spanner não tem capacidade para lidar solicitações que recebe.

Nesses cenários, um cliente precisa repetir a transação cancelada até que ele seja confirmado ou expire. Para usuários da interface oficial bibliotecas de cliente, cada biblioteca tem implementaram um mecanismo automático de nova tentativa. Se você estiver usando uma versão personalizada do código do cliente, una as confirmações de transação em um loop de repetição.

Uma transação do Spanner também pode ser cancelada devido a um erro que não permite novas tentativas como tempo limite da transação, problemas de permissão ou uma tabela/coluna inválida nome. Não é necessário repetir essas transações, e o Spanner biblioteca de cliente retornará o erro imediatamente.

A tabela a seguir descreve alguns exemplos de como COMMIT_ATTEMPT_COUNT, COMMIT_ABORT_COUNT e COMMIT_RETRY_COUNT são registrados em diferentes cenários.

Cenário	COMMIT_ATTEMPT_COUNT	COMMIT_ABORT_COUNT	COMMIT_RETRY_COUNT
Transação confirmada na primeira tentativa.	1	0	0
Transação cancelada devido a um erro de tempo limite.	1	1	0
Transação cancelada devido a um problema de rede temporário e confirmada após uma nova tentativa.	2	1	1
Cinco transações com o mesmo FPRINT são executadas em um intervalo de 10 minutos. 3 das transações foram confirmadas na primeira tentativa, e 2 foram canceladas e confirmadas na primeira tentativa.	7	2	2

Os dados nas tabelas de estatísticas da transação são dados agregados de um intervalo de tempo. Para um intervalo específico, é possível que um cancelamento de transação e uma nova tentativa ocorra em torno dos limites e caia em buckets diferentes. Como resultado, em um intervalo de tempo específico, as tentativas e cancelamentos podem não ser iguais.

Elas são projetadas para solucionar problemas e apresentar introspecção, mas não têm garantia de que sejam 100% precisas. As estatísticas são agregadas na memória antes de serem armazenados nas tabelas do Spanner. Durante um upgrade ou outra de manutenção, os servidores do Spanner podem ser reiniciados, afetando e a precisão dos números.

Resolver problemas de contenção de banco de dados usando estatísticas de transação

Use o código SQL ou os Insights sobre transações para exibir as transações em seu banco de dados que podem causar altas latências de rede devido a contenções de bloqueio.

Os tópicos a seguir mostram como investigar essas transações usando o código SQL.

Selecione um período para investigar

Isso pode ser encontrado no aplicativo que usa o Spanner.

Para os fins deste exercício, digamos que o problema começou a ocorrer às 17h20 do dia 17 de maio de 2020.

Você pode usar as tags de transação para identificar a origem da transação e correlacionar as tabelas de estatísticas de transação e de estatísticas de bloqueio para uma solução de problemas eficiente para a contenção de bloqueios. Leia mais sobre como resolver problemas com tags de transação.

Coletar estatísticas de transações para o período selecionado

Para iniciar nossa investigação, consultaremos a tabela TXN_STATS_TOTAL_10MINUTE em torno do início do problema. Os resultados dessa consulta mostrarão como a latência e outras estatísticas de transação foram alteradas durante esse período.

Por exemplo, a consulta a seguir retorna as estatísticas de transações agregadas de 4:30 pm para 7:40 pm (inclusive).

SELECT
  interval_end,
  ROUND(avg_total_latency_seconds,4) as avg_total_latency_seconds,
  commit_attempt_count,
  commit_abort_count
FROM SPANNER_SYS.TXN_STATS_TOTAL_10MINUTE
WHERE
  interval_end >= "2020-05-17T16:40:00"
  AND interval_end <= "2020-05-17T19:40:00"
ORDER BY interval_end;

A tabela a seguir lista exemplos de dados retornados da nossa consulta.

interval_end	avg_total_latency_seconds	commit_attempt_count	commit_abort_count
2020-05-17 16:40:00-07:00	0,0284	315691	5170
2020-05-17 16:50:00-07:00	0,0250	302124	3828
2020-05-17 17:00:00-07:00	0,0460	346087	11382
2020-05-17 17:10:00-07:00	0,0864	379964	33826
2020-05-17 17:20:00-07:00	0,1291	390343	52549
2020-05-17 17:30:00-07:00	0,1314	456455	76392
2020-05-17 17:40:00-07:00	0,1598	507774	121458
2020-05-17 17:50:00-07:00	0,1641	516587	115875
2020-05-17 18:00:00-07:00	0,1578	552711	122626
2020-05-17 18:10:00-07:00	0,1750	569460	154205
2020-05-17 18:20:00-07:00	0,1727	613571	160772
2020-05-17 18:30:00-07:00	0,1588	601994	143044
2020-05-17 18:40:00-07:00	0,2025	604211	170019
2020-05-17 18:50:00-07:00	0,1615	601622	135601
2020-05-17 19:00:00-07:00	0,1653	596804	129511
2020-05-17 19:10:00-07:00	0,1414	560023	112247
2020-05-17 19:20:00-07:00	0,1367	570864	100596
2020-05-17 19:30:00-07:00	0,0894	539729	65316
2020-05-17 19:40:00-07:00	0,0820	479151	40398

Aqui, vemos que a latência agregada e a contagem de cancelamentos são maiores nos períodos destacados. Podemos escolher qualquer intervalo de 10 minutos em que a latência agregada e/ou a contagem de cancelamentos sejam altas. Vamos escolher o intervalo que termina em 2020-05-17T18:40:00 e usá-lo na próxima etapa para identificar quais transações contribuem para a alta latência e a contagem de cancelamentos.

Identifique as transações com alta latência

Agora, consultaremos a tabela TXN_STATS_TOP_10MINUTE em busca do intervalo escolhido na etapa anterior. Usando esses dados, podemos começar a identificar quais transações apresentam alta latência e/ou alta contagem de cancelamentos.

Execute a consulta a seguir para receber as principais transações que afetam o desempenho em ordem decrescente de latência total para nosso intervalo de exemplo que termina em 2020-05-17T18:40:00.

SELECT
  interval_end,
  fprint,
  ROUND(avg_total_latency_seconds,4) as avg_total_latency_seconds,
  ROUND(avg_commit_latency_seconds,4) as avg_commit_latency_seconds,
  commit_attempt_count,
  commit_abort_count,
  commit_retry_count
FROM SPANNER_SYS.TXN_STATS_TOP_10MINUTE
WHERE
  interval_end = "2020-05-17T18:40:00"
ORDER BY avg_total_latency_seconds DESC;

interval_end	fprint	avg_total_latency_seconds	avg_commit_latency_seconds	commit_attempt_count	commit_abort_count	commit_retry_count
2020-05-17 18:40:00-07:00	15185072816865185658	0,3508	0,0139	278802	142205	129884
2020-05-17 18:40:00-07:00	15435530087434255496	0,1633	0,0142	129012	27177	24559
2020-05-17 18:40:00-07:00	14175643543447671202	0,1423	0,0133	5357	636	433
2020-05-17 18:40:00-07:00	898069986622520747	0,0198	0,0158	6	0	0
2020-05-17 18:40:00-07:00	10510121182038036893	0,0168	0,0125	7	0	0
2020-05-17 18:40:00-07:00	9287748709638024175	0,0159	0,0118	4269	1	0
2020-05-17 18:40:00-07:00	7129109266372596045	0,0142	0,0102	182227	0	0
2020-05-17 18:40:00-07:00	15630228555662391800	0,0120	0,0107	58	0	0
2020-05-17 18:40:00-07:00	7907238229716746451	0,0108	0,0097	65	0	0
2020-05-17 18:40:00-07:00	10158167220149989178	0,0095	0,0047	3454	0	0
2020-05-17 18:40:00-07:00	9353100217060788102	0,0093	0,0045	725	0	0
2020-05-17 18:40:00-07:00	9521689070912159706	0,0093	0,0045	164	0	0
2020-05-17 18:40:00-07:00	11079878968512225881	0,0064	0,0019	65	0	0

Podemos ver claramente que a primeira linha (destacada) na tabela anterior mostra uma transação com alta latência devido a um grande número de cancelamentos de confirmação. Também podemos ver um alto número de novas tentativas de confirmação, o que indica que as confirmações canceladas foram repetidas. Na próxima etapa, investigaremos mais a causa do problema.

Identifique as colunas envolvidas em uma transação com alta latência

Nesta etapa, verificaremos se as transações de alta latência estão operando no mesmo conjunto de colunas, buscando dados read_columns, write_constructive_columns e write_delete_tables para transações com alta contagem de cancelamentos. O valor FPRINT também será útil na próxima etapa.

SELECT
  fprint,
  read_columns,
  write_constructive_columns,
  write_delete_tables
FROM SPANNER_SYS.TXN_STATS_TOP_10MINUTE
WHERE
  interval_end = "2020-05-17T18:40:00"
ORDER BY avg_total_latency_seconds DESC LIMIT 3;

fprint	read_columns	write_constructive_columns	write_delete_tables
15185072816865185658	`[TestHigherLatency._exists,TestHigherLatency.lang_status,TestHigherLatency.score,globalTagAffinity.shares]`	`[TestHigherLatency._exists,TestHigherLatency.shares,TestHigherLatency_lang_status_score_index.shares]`	[]
15435530087434255496	`[TestHigherLatency._exists,TestHigherLatency.lang_status,TestHigherLatency.likes,globalTagAffinity.score]`	`[TestHigherLatency._exists,TestHigherLatency.likes,TestHigherLatency_lang_status_score_index.likes]`	[]
14175643543447671202	`[TestHigherLatency._exists,TestHigherLatency.lang_status,TestHigherLatency.score,globalTagAffinity.ugcCount]`	`[TestHigherLatency._exists,TestHigherLatency.ugcCount,TestHigherLatency_lang_status_score_index.ugcCount]`	[]

Como mostrado na tabela anterior, as transações com a latência média total mais alta são lidas pelas mesmas colunas. Também é possível observar alguma contenção de gravação porque as transações estão gravando na mesma coluna, ou seja, TestHigherLatency._exists.

determinar como o desempenho da transação mudou ao longo do tempo;

Podemos ver como as estatísticas associadas a essa forma de transação foram alteradas ao longo de um período. Use a consulta a seguir, em que $FPRINT é a impressão digital da transação de alta latência da etapa anterior.

SELECT
  interval_end,
  ROUND(avg_total_latency_seconds, 3) AS latency,
  ROUND(avg_commit_latency_seconds, 3) AS commit_latency,
  commit_attempt_count,
  commit_abort_count,
  commit_retry_count,
  commit_failed_precondition_count,
  avg_bytes
FROM SPANNER_SYS.TXN_STATS_TOP_10MINUTE
WHERE
  interval_end >= "2020-05-17T16:40:00"
  AND interval_end <= "2020-05-17T19:40:00"
  AND fprint = $FPRINT
ORDER BY interval_end;

interval_end	latency	commit_latency	commit_attempt_count	commit_abort_count	commit_retry_count	avg_bytes
2020-05-17 16:40:00-07:00	0,095	0,010	53230	4752	4330	91
2020-05-17 16:50:00-07:00	0,069	0,009	61264	3589	3364	91
2020-05-17 17:00:00-07:00	0,150	0,010	75868	10557	9322	91
2020-05-17 17:10:00-07:00	0.248	0,013	103151	30220	28483	91
2020-05-17 17:20:00-07:00	0.310	0.012	130078	45655	41966	91
2020-05-17 17:30:00-07:00	0.294	0.012	160064	64930	59933	91
2020-05-17 17:40:00-07:00	0.315	0,013	209614	104949	96770	91
2020-05-17 17:50:00-07:00	0.322	0.012	215682	100408	95867	90
2020-05-17 18:00:00-07:00	0.310	0.012	230932	106728	99462	91
2020-05-17 18:10:00-07:00	0.309	0.012	259645	131049	125889	91
2020-05-17 18:20:00-07:00	0.315	0,013	272171	137910	129411	90
2020-05-17 18:30:00-07:00	0,292	0,013	258944	121475	115844	91
2020-05-17 18:40:00-07:00	0,350	0,013	278802	142205	134229	91
2020-05-17 18:50:00-07:00	0,302	0,013	256259	115626	109756	91
2020-05-17 19:00:00-07:00	0.315	0,014	250560	110662	100322	91
2020-05-17 19:10:00-07:00	0,271	0,014	238384	99025	90187	91
2020-05-17 19:20:00-07:00	0,273	0,014	219687	84019	79874	91
2020-05-17 19:30:00-07:00	0,198	0,013	195357	59370	55909	91
2020-05-17 19:40:00-07:00	0,181	0,013	167514	35705	32885	91

Na saída acima, podemos observar que a latência total é alta para o período destacado. E, sempre que a latência total for alta, commit_attempt_count, commit_abort_count e commit_retry_count também serão altos, mesmo que a latência de confirmação (commit_latency) não tenha mudado muito. Como as confirmações de transação são canceladas com mais frequência, as tentativas de confirmação também são altas devido a novas tentativas de confirmação.

Conclusão

Neste exemplo, vemos que a alta contagem de cancelamentos de confirmação foi a causa da alta latência. A próxima etapa é analisar as mensagens de erro de cancelamento de confirmação recebidas pelo aplicativo para saber o motivo dos cancelamentos. Ao inspecionar registros no aplicativo, vemos que ele realmente alterou a carga de trabalho durante esse período, ou seja, outra forma de transação foi mostrada com attempts_per_second alto, e essa transação diferente (talvez um job de limpeza noturna) foi responsável pelos conflitos de bloqueio adicionais.

Identifique as transações em que não foram feitas novas tentativas corretamente.

A consulta a seguir retorna as transações amostradas nos últimos dez minutos que têm uma alta contagem de cancelamento de confirmação, mas sem novas tentativas.

SELECT
  *
FROM (
  SELECT
    fprint,
    SUM(commit_attempt_count) AS total_commit_attempt_count,
    SUM(commit_abort_count) AS total_commit_abort_count,
    SUM(commit_retry_count) AS total_commit_retry_count
  FROM
    SPANNER_SYS.TXN_STATS_TOP_10MINUTE
  GROUP BY
    fprint )
WHERE
  total_commit_retry_count = 0
  AND total_commit_abort_count > 0
ORDER BY
  total_commit_abort_count DESC;

fprint	total_commit_attempt_count	total_commit_abort_count	total_commit_retry_count
1557557373282541312	3367894	44232	0
5776062322886969344	13566	14	0

Vemos que a transação com fprint 1557557373282541312 foi cancelada 44232 vezes, mas nunca foi repetida. Isso parece suspeito, porque a contagem de cancelamentos é alta e é improvável que cada cancelamento tenha sido causado por um erro que não pode ser recuperado. Por outro lado, para a transação com fprint 5776062322886969344, é menos suspeita, porque a contagem total de cancelamentos não é tão alta.

A consulta a seguir retorna mais detalhes sobre a transação com fprint 1557557373282541312,incluindo read_columns, write_constructive_columns e write_delete_tables. Essas informações ajudam a identificar a transação no código do cliente, em que a lógica de repetição pode ser analisada para esse cenário.

SELECT
  interval_end,
  fprint,
  read_columns,
  write_constructive_columns,
  write_delete_tables,
  commit_attempt_count,
  commit_abort_count,
  commit_retry_count
FROM
  SPANNER_SYS.TXN_STATS_TOP_10MINUTE
WHERE
  fprint = 1557557373282541312
ORDER BY
  interval_end DESC;

interval_end	fprint	read_columns	write_constructive_columns	write_delete_tables	commit_attempt_count	commit_abort_count
2021-01-27T18:30:00Z	1557557373282541312	['Singers._exists']	['Singers.FirstName', 'Singers.LastName', 'Singers._exists']	[]	805228	1839
2021-01-27T18:20:00Z	1557557373282541312	['Singers._exists']	['Singers.FirstName', 'Singers.LastName', 'Singers._exists']	[]	1034429	38779
2021-01-27T18:10:00Z	1557557373282541312	['Singers._exists']	['Singers.FirstName', 'Singers.LastName', 'Singers._exists']	[]	833677	2266
2021-01-27T18:00:00Z	1557557373282541312	['Singers._exists']	['Singers.FirstName', 'Singers.LastName', 'Singers._exists']	[]	694560	1348

A transação envolve uma leitura na coluna oculta Singers._exists para verificar a existência de uma linha. A transação também grava nas colunas Singers.FirstName e Singer.LastName. Essas informações podem ajudar a determinar se o mecanismo de repetição de transação implementado na sua biblioteca de cliente personalizada está funcionando conforme o esperado.

A seguir

Saiba mais sobre outras ferramentas de introspecção.
Saiba mais sobre outras informações que o Spanner armazena para cada banco de dados no tabelas do esquema de informações do banco de dados.
Saiba mais sobre práticas recomendadas de SQL para no Spanner.
Saiba mais sobre como investigar a alta utilização da CPU.