Spanner fornisce tabelle integrate che memorizzano statistiche sulle transazioni. Puoi recuperare le statistiche da queste tabelle SPANNER_SYS.TXN_STATS*
utilizzando le istruzioni SQL.
Quando utilizzare le statistiche sulle transazioni
Le statistiche sulle transazioni sono utili per esaminare i problemi di prestazioni. Ad esempio, puoi controllare se sono presenti transazioni a esecuzione lenta che potrebbero influire sul rendimento o sulle query al secondo (QPS) nel tuo database. Un altro scenario è quando le applicazioni client presentano una latenza di esecuzione delle transazioni elevata. L'analisi delle statistiche sulle transazioni può contribuire a scoprire potenziali colli di bottiglia, ad esempio grandi volumi di aggiornamenti di una determinata colonna, che potrebbero influire sulla latenza.
Disponibilità
I dati di SPANNER_SYS
sono disponibili solo tramite interfacce SQL, ad esempio:
Pagina Spanner Studio di un database nella console Google Cloud
Il comando
gcloud spanner databases execute-sql
La dashboard Insight sulle transazioni
L'API
executeQuery
Gli altri metodi di lettura singola forniti da Spanner non supportanoSPANNER_SYS
.
Statistiche sulla latenza raggruppate per transazione
Le tabelle seguenti monitorano le statistiche relative alle transazioni che consumano risorse TOP
durante un periodo di tempo specifico.
SPANNER_SYS.TXN_STATS_TOP_MINUTE
: statistiche sulle transazioni aggregate in intervalli di 1 minuto.SPANNER_SYS.TXN_STATS_TOP_10MINUTE
: statistiche sulle transazioni aggregate su intervalli di 10 minuti.SPANNER_SYS.TXN_STATS_TOP_HOUR
: statistiche sulle transazioni aggregate in intervalli di 1 ora.
Queste tabelle hanno le seguenti proprietà:
Ogni tabella contiene dati per intervalli di tempo non sovrapposti della durata specificata dal nome della tabella.
Gli intervalli si basano sugli orari dell'orologio. Gli intervalli di 1 minuto terminano al minuto, quelli di 10 minuti terminano ogni 10 minuti a partire dall'ora e quelli di 1 ora terminano all'ora.
Ad esempio, alle 00:59:30, gli intervalli più recenti disponibili per le query SQL sono:
- 1 minuto: dalle 00:58:00 alle 00:58:59
- 10 minuti: 11:40:00-11:49:59
- 1 ora: dalle 10:00:00 alle 10:59:59 AM
Spanner raggruppa le statistiche per FINGERPRINT (impronta) delle transazioni. Se è presente un tag transazione, FPRINT è l'hash del tag. In caso contrario, si tratta dell'hash calcolato in base alle operazioni coinvolte nella transazione.
Poiché le statistiche sono raggruppate in base a FPRINT, se la stessa transazione viene eseguita più volte in qualsiasi intervallo di tempo, in queste tabelle viene visualizzata una sola voce per la transazione.
Ogni riga contiene le statistiche relative a tutte le esecuzioni di una determinata transazione per le quali Spanner acquisisce le statistiche durante l'intervallo specificato.
Se Spanner non è in grado di memorizzare le statistiche per tutte le transazioni eseguite durante l'intervallo in queste tabelle, il sistema dà la priorità alle transazioni con la latenza, i tentativi di commit e i byte scritti più elevati durante l'intervallo specificato.
Tutte le colonne delle tabelle sono nullable.
Schema tabella
Nome colonna | Tipo | Descrizione |
---|---|---|
INTERVAL_END |
TIMESTAMP |
Fine dell'intervallo di tempo in cui si sono verificate le esecuzioni di transazioni incluse. |
TRANSACTION_TAG |
STRING |
Il tag transazione facoltativo per questa operazione di transazione. Per ulteriori informazioni sull'utilizzo dei tag, consulta Risoluzione dei problemi relativi ai tag transazioni. Le statistiche relative a più transazioni con la stessa stringa di tag vengono raggruppate in un'unica riga con il valore "TRANSACTION_TAG" corrispondente a quella stringa di tag. |
FPRINT |
INT64 |
L'hash del TRANSACTION_TAG , se presente. In caso contrario,
l'hash viene calcolato in base alle operazioni coinvolte nella transazione.
INTERVAL_END e FPRINT insieme fungono da
chiave univoca per queste tabelle. |
READ_COLUMNS |
ARRAY<STRING> |
L'insieme di colonne lette dalla transazione. |
WRITE_CONSTRUCTIVE_COLUMNS |
ARRAY<STRING> |
L'insieme di colonne scritte in modo costruttivo (ovvero assegnate a nuovi valori) dalla transazione.
Per gli stream di modifiche, se la transazione prevede scritture in colonne e tavole monitorate da uno stream di modifiche, WRITE_CONSTRUCTIVE_COLUMNS
conterrà due colonne: .data e ._exists
1, con un prefisso che indica il nome dello stream di modifiche.
|
WRITE_DELETE_TABLES |
ARRAY<STRING> |
L'insieme di tabelle di cui le righe sono state eliminate o sostituite dalla transazione. |
ATTEMPT_COUNT |
INT64 |
Numero totale di tentativi di transazione, inclusi i tentativi che vengono interrotti prima di chiamare "commit". |
COMMIT_ATTEMPT_COUNT |
INT64 |
Numero totale di tentativi di commit delle transazioni. Deve corrispondere al numero
di chiamate al metodo commit della transazione.
|
COMMIT_ABORT_COUNT |
INT64 |
Numero totale di tentativi di transazione interrotti, inclusi quelli
che sono stati interrotti prima di chiamare il metodo commit
della transazione.
|
COMMIT_RETRY_COUNT |
INT64 |
Numero totale di tentativi che sono ripetizioni di tentativi precedentemente abbandonati. Una transazione Spanner potrebbe essere tentata più volte prima di essere confermata a causa di conflitti di blocco o eventi transitori. Un numero elevato di tentativi rispetto ai tentativi di commit indica che potrebbero esserci problemi che vale la pena esaminare. Per ulteriori informazioni, consulta Informazioni sui conteggi di transazioni e commit in questa pagina. |
COMMIT_FAILED_PRECONDITION_COUNT |
INT64 |
Numero totale di tentativi di commit delle transazioni che hanno restituito errori di precondizione non riusciti, come violazioni dell'indice UNIQUE , riga esistente, riga non trovata e così via.
|
AVG_PARTICIPANTS |
FLOAT64 |
Numero medio di partecipanti a ogni tentativo di commit. Per saperne di più su i partecipanti, consulta Durata di letture e scritture di Cloud Spanner. |
AVG_TOTAL_LATENCY_SECONDS |
FLOAT64 |
Secondi medi impiegati dalla prima operazione della transazione al commit/all'aborto. |
AVG_COMMIT_LATENCY_SECONDS |
FLOAT64 |
Secondi medi necessari per eseguire l'operazione di commit. |
AVG_BYTES |
FLOAT64 |
Numero medio di byte scritti dalla transazione. |
TOTAL_LATENCY_DISTRIBUTION |
ARRAY<STRUCT>
|
Un istogramma della latenza totale del commit, ovvero il tempo che intercorre tra la data di inizio della prima operazione di transazione e la data del commit o dell'interruzione per tutti i tentativi di una transazione.
Se una transazione viene interrotta più volte e poi viene eseguita correttamente, la latenza viene misurata per ogni tentativo fino all'ultimo commit riuscito. I valori sono misurati in secondi.
L'array contiene un singolo elemento ed è del seguente tipo:
Per calcolare la latenza percentile desiderata dalla distribuzione,
utilizza la funzione Per ulteriori informazioni, consulta Percentili e metriche con valori di distribuzione. |
OPERATIONS_BY_TABLE |
ARRAY<STRUCT> |
Impatto delle operazioni
Questa colonna consente di visualizzare il carico sulle tabelle e fornisce informazioni sulla frequenza con cui una transazione scrive nelle tabelle.
Specifica l'array come segue:
|
1 _exists
è un campo interno utilizzato per verificare se una determinata riga esiste o meno.
Esempi di query
Questa sezione include diversi esempi di istruzioni SQL che recuperano le statistiche sulle transazioni. Puoi eseguire queste istruzioni SQL utilizzando le librerie client, gcloud spanner o la console Google Cloud.
Elenca le statistiche di base per ogni transazione in un determinato periodo di tempo
La seguente query restituisce i dati non elaborati per le transazioni principali nel minuto precedente.
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);
Output della query
fprint | read_columns | scrivere_colonne_costruttive | 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 |
Elenca le transazioni con la latenza media del commit più elevata
La seguente query restituisce le transazioni con una latenza media di commit elevata nell'ora precedente, ordinate dalla latenza media di commit più alta a quella più bassa.
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;
Output della query
fprint | read_columns | scrivere_colonne_costruttive | 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 |
Trovare la latenza media delle transazioni che leggono determinate colonne
La seguente query restituisce le informazioni sulla latenza media per le transazioni che leggono la colonna ADDRESS dalle statistiche di un'ora:
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;
Output della query
fprint | read_columns | scrivere_colonne_costruttive | write_delete_tables | avg_total_latency_seconds |
---|---|---|---|---|
77848338483 |
["ID", "ADDRESS"] |
[] |
["Cars", "Routes"] |
0.033467418 |
40015598317 |
["ID", "NAME", "ADDRESS"] |
[] |
["Users"] |
0.006578737 |
Elenca le transazioni in base al numero medio di byte modificati
La seguente query restituisce le transazioni campionate nell'ultima ora, ordinate in base al numero medio di byte modificati dalla transazione.
SELECT fprint,
read_columns,
write_constructive_columns,
write_delete_tables,
avg_bytes
FROM spanner_sys.txn_stats_top_hour
ORDER BY avg_bytes DESC;
Output della query
fprint | read_columns | scrivere_colonne_costruttive | write_delete_tables | avg_bytes |
---|---|---|---|---|
40015598317 |
[] |
[] |
["Users"] |
25286 |
77848338483 |
[] |
[] |
["Cars", "Routes"] |
12005 |
20524969030 |
["ID", "ADDRESS"] |
[] |
["Users"] |
10923 |
Statistiche aggregate
SPANNER_SYS
contiene anche tabelle per archiviare i dati aggregati per tutte le transazioni per le quali Spanner ha acquisito le statistiche in un periodo di tempo specifico:
SPANNER_SYS.TXN_STATS_TOTAL_MINUTE
: statistiche aggregate per tutte le transazioni in intervalli di 1 minutoSPANNER_SYS.TXN_STATS_TOTAL_10MINUTE
: statistiche aggregate per tutte le transazioni durante intervalli di 10 minutiSPANNER_SYS.TXN_STATS_TOTAL_HOUR
: statistiche aggregate per tutte le transazioni durante intervalli di 1 ora
Le tabelle delle statistiche aggregate hanno le seguenti proprietà:
Ogni tabella contiene dati per intervalli di tempo non sovrapposti della durata specificata dal nome della tabella.
Gli intervalli si basano sull'ora dell'orologio. Gli intervalli di 1 minuto terminano al minuto, quelli di 10 minuti terminano ogni 10 minuti a partire dall'ora e quelli di 1 ora terminano all'ora.
Ad esempio, alle 00:59:30, gli intervalli più recenti disponibili per le query SQL sulle statistiche sulle transazioni aggregate sono:
- 1 minuto: dalle 00:58:00 alle 00:58:59
- 10 minuti: 11:40:00-11:49:59
- 1 ora: dalle 10:00:00 alle 10:59:59 AM
Ogni riga contiene le statistiche relative a tutte le transazioni eseguite sul database durante l'intervallo specificato, aggregate insieme. Esiste una sola riga per intervallo di tempo.
Le statistiche acquisite nelle tabelle
SPANNER_SYS.TXN_STATS_TOTAL_*
potrebbero includere transazioni che Spanner non ha acquisito nelle tabelleSPANNER_SYS.TXN_STATS_TOP_*
.Alcune colonne di queste tabelle sono esposte come metriche in Cloud Monitoring. Le metriche esposte sono:
- Numero di tentativi di commit
- Conteggio dei tentativi di commit
- Partecipanti alla transazione
- Latenze delle transazioni
- Byte scritti
Per ulteriori informazioni, consulta Metriche di Spanner.
Schema tabella
Nome colonna | Tipo | Descrizione |
---|---|---|
INTERVAL_END |
TIMESTAMP |
Fine dell'intervallo di tempo in cui è stata acquisita questa statistica. |
ATTEMPT_COUNT |
INT64 |
Numero totale di volte in cui vengono tentati i trasferimenti, inclusi i tentativi che vengono interrotti prima di chiamare "commit". |
COMMIT_ATTEMPT_COUNT |
INT64 |
Numero totale di tentativi di commit delle transazioni. Deve corrispondere al numero
di chiamate al metodo commit della transazione.
|
COMMIT_ABORT_COUNT |
INT64 |
Numero totale di tentativi di transazione interrotti, inclusi quelli
che vengono interrotti prima di chiamare il metodo commit
della transazione. |
COMMIT_RETRY_COUNT |
INT64 |
Numero di tentativi di commit che sono ripetizioni di tentativi precedentemente abortiti. Una transazione Spanner potrebbe essere stata tentata più volte prima di essere confermata a causa di conflitti di blocco o eventi transitori. Un numero elevato di tentativi rispetto ai tentativi di commit indica che potrebbero esserci problemi che vale la pena esaminare. Per ulteriori informazioni, consulta Informazioni sui conteggi di transazioni e commit in questa pagina. |
COMMIT_FAILED_PRECONDITION_COUNT |
INT64 |
Numero totale di tentativi di commit delle transazioni che hanno restituito errori di precondizione non riusciti, come violazioni dell'indice UNIQUE , riga esistente, riga non trovata e così via.
|
AVG_PARTICIPANTS |
FLOAT64 |
Numero medio di partecipanti a ogni tentativo di commit. Per saperne di più su i partecipanti, consulta Durata di letture e scritture di Cloud Spanner. |
AVG_TOTAL_LATENCY_SECONDS |
FLOAT64 |
Secondi medi impiegati dalla prima operazione della transazione al commit/all'aborto. |
AVG_COMMIT_LATENCY_SECONDS |
FLOAT64 |
Secondi medi necessari per eseguire l'operazione di commit. |
AVG_BYTES |
FLOAT64 |
Numero medio di byte scritti dalla transazione. |
TOTAL_LATENCY_DISTRIBUTION |
ARRAY<STRUCT>
|
Un istogramma della latenza totale del commit, ovvero il tempo che intercorre tra la data di inizio della prima operazione di transazione e la data di commit o di interruzione per tutti i tentativi di transazione.
Se una transazione viene interrotta più volte e poi viene eseguita correttamente, la latenza viene misurata per ogni tentativo fino all'ultimo commit riuscito. I valori sono misurati in secondi.
L'array contiene un singolo elemento ed è del seguente tipo:
Per calcolare la latenza percentile desiderata dalla distribuzione,
utilizza la funzione Per ulteriori informazioni, consulta Percentili e metriche con valori di distribuzione. |
OPERATIONS_BY_TABLE |
ARRAY<STRUCT> |
Impatto delle operazioni
Questa colonna consente di visualizzare il carico sulle tabelle e fornisce informazioni sulla frequenza con cui le transazioni scrivono nelle tabelle.
Specifica l'array come segue:
|
Esempi di query
Questa sezione include diversi esempi di istruzioni SQL che recuperano le statistiche sulle transazioni. Puoi eseguire queste istruzioni SQL utilizzando le librerie client, gcloud spanner o la console Google Cloud.
Trova il numero totale di tentativi di commit per tutte le transazioni
La seguente query restituisce il numero totale di tentativi di commit per tutte le transazioni nell'intervallo di 1 minuto completo più 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;
Output della query
interval_end | commit_attempt_count |
---|---|
2020-01-17 11:46:00-08:00 |
21 |
Tieni presente che il risultato contiene una sola riga perché le statistiche aggregate hanno una sola voce per interval_end
per qualsiasi durata temporale.
Trovare la latenza di commit totale in tutte le transazioni
La seguente query restituisce la latenza totale del commit per tutte le transazioni negli gli ultimi 10 minuti:
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);
Output della query
total_commit_latency_hours |
---|
0.8967 |
Tieni presente che il risultato contiene una sola riga perché le statistiche aggregate hanno una sola voce per interval_end
per qualsiasi durata temporale.
Trovare la latenza del 99° percentile per le transazioni
La seguente query restituisce la latenza del 99° percentile per le transazioni eseguite negli 10 minuti precedenti:
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;
Output della query
interval_end | avg_total_latency_seconds | percentile_latency |
---|---|---|
2022-08-17 11:46:00-08:00 |
0.34576998305986395 |
9.00296190476190476 |
Nota la grande differenza tra la latenza media e quella del 99° percentile. La latenza del 99° percentile consente di identificare possibili transazioni outlier con alta latenza.
Il risultato contiene una sola riga perché le statistiche aggregate hanno solo una voce per interval_end
per qualsiasi durata temporale.
Conservazione dei dati
Come minimo, Spanner conserva i dati per ogni tabella per i seguenti periodi di tempo:
SPANNER_SYS.TXN_STATS_TOP_MINUTE
eSPANNER_SYS.TXN_STATS_TOTAL_MINUTE
: intervalli che coprono le 6 ore precedenti.SPANNER_SYS.TXN_STATS_TOP_10MINUTE
eSPANNER_SYS.TXN_STATS_TOTAL_10MINUTE
: intervalli che coprono i 4 giorni precedenti.SPANNER_SYS.TXN_STATS_TOP_HOUR
eSPANNER_SYS.TXN_STATS_TOTAL_HOUR
: intervalli che coprono i 30 giorni precedenti.
Le statistiche sulle transazioni in Spanner forniscono informazioni su come un'applicazione utilizza il database e sono utili per esaminare i problemi di prestazioni. Ad esempio, puoi verificare se sono presenti transazioni in esecuzione lenta che potrebbero causare contese oppure identificare potenziali fonti di carico elevato, come grandi volumi di aggiornamenti a una determinata colonna. Seguendo i passaggi riportati di seguito, ti mostreremo come utilizzare le statistiche sulle transazioni per esaminare le contese nel tuo database.
Informazioni sui conteggi di transazioni e commit
Potrebbe essere necessario provare una transazione Spanner più volte prima che venga eseguita. Questo accade più comunemente quando due transazioni tentano di lavorare sugli stessi dati contemporaneamente e una delle transazioni deve essere interrotta per preservare la proprietà di isolamento della transazione. Alcuni altri eventi temporanei che possono anche causare l'interruzione di una transazione includono:
Problemi di rete temporanei.
Modifiche allo schema del database applicate durante il commit di una transazione.
L'istanza Spanner non ha la capacità di gestire tutte le richieste che riceve.
In questi scenari, un client deve riprovare la transazione interrotta finché non viene eseguita correttamente o non scade il tempo di attesa. Per gli utenti delle librerie client ufficiali di Spanner, ogni libreria ha implementato un meccanismo di ripetizione automatica. Se utilizzi una versione personalizzata del codice client, inserisci i commit delle transazioni in un ciclo di ripetizione.
Una transazione Spanner può essere interrotta anche a causa di un errore non recuperabile, come un timeout della transazione, problemi di autorizzazione o un nome di tabella/colonna non valido. Non è necessario ripetere queste transazioni e la libreria client Spanner restituirà immediatamente l'errore.
La tabella seguente descrive alcuni esempi di come COMMIT_ATTEMPT_COUNT
,
COMMIT_ABORT_COUNT
e COMMIT_RETRY_COUNT
vengono registrati in scenari diversi.
Scenario | COMMIT_ATTEMPT_COUNT | COMMIT_ABORT_COUNT | COMMIT_RETRY_COUNT |
---|---|---|---|
Transazione eseguita correttamente al primo tentativo. | 1 | 0 | 0 |
Transazione interrotta a causa di un errore di timeout. | 1 | 1 | 0 |
Transazione interrotta a causa di un problema di rete temporaneo e avviata correttamente dopo un nuovo tentativo. | 2 | 1 | 1 |
5 transazioni con lo stesso FPRINT vengono eseguite in un intervallo di 10 minuti. 3 delle transazioni sono state committate correttamente al primo tentativo, mentre 2 transazioni sono state interrotte e poi committate correttamente al primo tentativo. | 7 | 2 | 2 |
I dati nelle tabelle transactions-stats sono dati aggregati per un intervallo di tempo. Per un determinato intervallo, è possibile che una transazione venga interrotta e riprovata intorno ai confini e rientri in bucket diversi. Di conseguenza, in un determinato intervallo di tempo gli aborti e i tentativi di nuovo avvio potrebbero non essere uguali.
Queste statistiche sono progettate per la risoluzione dei problemi e l'introspezione e non è garantita la loro precisione al 100%. Le statistiche vengono aggregate in memoria prima di essere archiviate nelle tabelle Spanner. Durante un upgrade o altre attività di manutenzione, i server Spanner possono riavviarsi, influenzando l'accuratezza dei numeri.
Risolvere i problemi di contesa del database utilizzando le statistiche sulle transazioni
Puoi utilizzare il codice SQL o la dashboard Approfondimenti sulle transazioni per visualizzare le transazioni nel tuo database che potrebbero causare latenze elevate a causa di conflitti di blocco.
I seguenti argomenti mostrano come esaminare queste transazioni utilizzando il codice SQL.
Seleziona un periodo di tempo da esaminare
Puoi trovarlo nell'applicazione che utilizza Spanner.
Ai fini di questo esercizio, supponiamo che il problema abbia iniziato a verificarsi alle ore 17:20 circa del 17 maggio 2020.
Puoi utilizzare i tag transazioni per identificare l'origine della transazione e eseguire la correlazione tra le tabelle Statistiche delle transazioni e Statistiche dei blocchi per risolvere efficacemente i problemi di contesa dei blocchi. Scopri di più nella sezione Risoluzione dei problemi relativi ai tag transazione.
Raccogliere le statistiche sulle transazioni per il periodo di tempo selezionato
Per iniziare la nostra indagine, eseguiremo una query sulla tabella TXN_STATS_TOTAL_10MINUTE
intorno all'inizio del problema. I risultati di questa query ci mostreranno come la latenza e altre statistiche sulle transazioni sono cambiate in questo periodo di tempo.
Ad esempio, la seguente query restituisce le statistiche sulle transazioni aggregate
da 4:30 pm
a 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;
La tabella seguente elenca i dati di esempio restituiti dalla nostra query.
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 |
Qui vediamo che il numero di interruzioni e la latenza aggregata sono più elevati nei periodi evidenziati. Possiamo scegliere qualsiasi intervallo di 10 minuti in cui la latenza aggregata
e/o il numero di interruzioni sono elevati. Scegli l'intervallo che termina alle 2020-05-17T18:40:00
e utilizzalo nel passaggio successivo per identificare le transazioni che contribuiscono a un numero elevato di aborti e a una latenza elevata.
Identifica le transazioni con latenza elevata
Ora eseguiamo una query sulla tabella TXN_STATS_TOP_10MINUTE
per l'intervallo scelto nel passaggio precedente. Utilizzando questi dati, possiamo iniziare a identificare le transazioni con latenza elevata e/o con un numero elevato di interruzioni.
Esegui la seguente query per ottenere le transazioni che influiscono maggiormente sul rendimento in ordine decrescente di latenza totale per l'intervallo di esempio che termina alle ore 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 |
Possiamo vedere chiaramente che la prima riga (evidenziata) nella tabella precedente mostra una transazione con una latenza elevata a causa di un numero elevato di aborti di commit. Possiamo anche vedere un numero elevato di tentativi di commit, il che indica che i commit abortiti sono stati successivamente riprovati. Nel passaggio successivo, effettueremo ulteriori accertamenti per capire cosa causa il problema.
Identificare le colonne coinvolte in una transazione con latenza elevata
In questo passaggio, verificheremo se le transazioni ad alta latenza operano sullo stesso insieme di colonne recuperando i dati di read_columns
, write_constructive_columns
e
write_delete_tables
per le transazioni con un conteggio degli aborti elevato. Il valore FPRINT
sarà utile anche nel passaggio successivo.
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 | scrivere_colonne_costruttive | 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] |
[] |
Come mostrato dall'output nella tabella precedente, le transazioni con la latenza media complessiva più elevata leggono le stesse colonne. Possiamo anche osservare alcune competizioni di scrittura poiché le transazioni scrivono nella stessa colonna, ovvero TestHigherLatency._exists
.
Determinare in che modo il rendimento delle transazioni è cambiato nel tempo
Possiamo vedere come le statistiche associate a questa forma di transazione sono cambiate in un determinato periodo di tempo. Utilizza la seguente query, dove $FPRINT è l'impronta della transazione ad alta latenza del passaggio precedente.
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 | latenza | commit_latency | commit_attempt_count | commit_abort_count | commit_retry_count | commit_failed_precondition_count | avg_bytes |
---|---|---|---|---|---|---|---|
2020-05-17 16:40:00-07:00 | 0,095 | 0,010 | 53230 | 4752 | 4330 | 0 | 91 |
2020-05-17 16:50:00-07:00 | 0,069 | 0,009 | 61264 | 3589 | 3364 | 0 | 91 |
2020-05-17 17:00:00-07:00 | 0,150 | 0,010 | 75868 | 10557 | 9322 | 0 | 91 |
2020-05-17 17:10:00-07:00 | 0,248 | 0,013 | 103151 | 30220 | 28483 | 0 | 91 |
2020-05-17 17:20:00-07:00 | 0,310 | 0,012 | 130078 | 45655 | 41966 | 0 | 91 |
2020-05-17 17:30:00-07:00 | 0,294 | 0,012 | 160064 | 64930 | 59933 | 0 | 91 |
2020-05-17 17:40:00-07:00 | 0,315 | 0,013 | 209614 | 104949 | 96770 | 0 | 91 |
2020-05-17 17:50:00-07:00 | 0,322 | 0,012 | 215682 | 100408 | 95867 | 0 | 90 |
2020-05-17 18:00:00-07:00 | 0,310 | 0,012 | 230932 | 106728 | 99462 | 0 | 91 |
2020-05-17 18:10:00-07:00 | 0,309 | 0,012 | 259645 | 131049 | 125889 | 0 | 91 |
2020-05-17 18:20:00-07:00 | 0,315 | 0,013 | 272171 | 137910 | 129411 | 0 | 90 |
2020-05-17 18:30:00-07:00 | 0,292 | 0,013 | 258944 | 121475 | 115844 | 0 | 91 |
2020-05-17 18:40:00-07:00 | 0,350 | 0,013 | 278802 | 142205 | 134229 | 0 | 91 |
2020-05-17 18:50:00-07:00 | 0,302 | 0,013 | 256259 | 115626 | 109756 | 0 | 91 |
2020-05-17 19:00:00-07:00 | 0,315 | 0,014 | 250560 | 110662 | 100322 | 0 | 91 |
2020-05-17 19:10:00-07:00 | 0,271 | 0,014 | 238384 | 99025 | 90187 | 0 | 91 |
2020-05-17 19:20:00-07:00 | 0,273 | 0,014 | 219687 | 84019 | 79874 | 0 | 91 |
2020-05-17 19:30:00-07:00 | 0,198 | 0,013 | 195357 | 59370 | 55909 | 0 | 91 |
2020-05-17 19:40:00-07:00 | 0,181 | 0,013 | 167514 | 35705 | 32885 | 0 | 91 |
Nell'output riportato sopra possiamo osservare che la latenza totale è elevata per il periodo di tempo evidenziato. Inoltre, se la latenza totale è elevata, lo sono anche commit_attempt_count
commit_abort_count
e commit_retry_count
, anche se la latenza
del commit (commit_latency
) non è cambiata molto. Poiché i commit delle transazioni vengono interrotti più di frequente, anche i tentativi di commit sono elevati a causa dei retry dei commit.
Conclusione
In questo esempio, abbiamo notato che un numero elevato di aborti dei commit era la causa di una latenza elevata. Il passaggio successivo consiste nell'esaminare i messaggi di errore di interruzione del commit ricevuti dall'applicazione per conoscere il motivo dell'interruzione. Esaminando i log nell'applicazione, abbiamo notato che l'applicazione ha effettivamente modificato il proprio carico di lavoro durante questo periodo, ovvero è stata visualizzata un'altra forma di transazione con un valore attempts_per_second
elevato e che una transazione diversa (forse un job di pulizia notturna) era responsabile dei conflitti di blocco aggiuntivi.
Identificare le transazioni per le quali non è stato eseguito correttamente un nuovo tentativo
La seguente query restituisce le transazioni campionate negli ultimi dieci minuti che hanno un conteggio elevato di aborti dei commit, ma nessuna ripetizione.
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 |
Possiamo vedere che la transazione con fprint 1557557373282541312 è stata interrotta 44232 volte, ma non è stato mai eseguito un nuovo tentativo. Questo sembra sospetto perché il numero di aborti è elevato ed è improbabile che ogni interruzione sia stata causata da un errore non recuperabile. D'altra parte, per la transazione con fprint 5776062322886969344, è meno sospetta perché il numero totale di aborti non è così elevato.
La seguente query restituisce ulteriori dettagli sulla transazione con fprint
1557557373282541312,inclusi read_columns
,write_constructive_columns
e write_delete_tables
. Queste informazioni aiutano a identificare la transazione nel codice client, dove è possibile esaminare la logica di ripetizione per questo scenario.
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 | scrivere_colonne_costruttive | write_delete_tables | commit_attempt_count | commit_abort_count | commit_retry_count |
---|---|---|---|---|---|---|---|
2021-01-27T18:30:00Z | 1557557373282541312 | ['Singers._exists'] | ['Singers.FirstName', 'Singers.LastName', 'Singers._exists'] | [] | 805228 | 1839 | 0 |
2021-01-27T18:20:00Z | 1557557373282541312 | ['Singers._exists'] | ['Singers.FirstName', 'Singers.LastName', 'Singers._exists'] | [] | 1034429 | 38779 | 0 |
2021-01-27T18:10:00Z | 1557557373282541312 | ['Singers._exists'] | ['Singers.FirstName', 'Singers.LastName', 'Singers._exists'] | [] | 833677 | 2266 | 0 |
2021-01-27T18:00:00Z | 1557557373282541312 | ['Singers._exists'] | ['Singers.FirstName', 'Singers.LastName', 'Singers._exists'] | [] | 694560 | 1348 | 0 |
Possiamo vedere che la transazione prevede una lettura della colonna nascosta Singers._exists
per verificare l'esistenza di una riga. La transazione scrive anche nelle colonne Singers.FirstName
e Singer.LastName
. Queste informazioni possono aiutarti a determinare se il meccanismo di ripetizione delle transazioni implementato nella libreria client personalizzata funziona come previsto.
Passaggi successivi
- Scopri altri strumenti di introspezione.
- Scopri altre informazioni archiviate da Spanner per ogni database nelle tabelle dello schema delle informazioni del database.
- Scopri di più sulle best practice per SQL per Spanner.
- Scopri di più su come esaminare l'utilizzo elevato della CPU.