Cloud Spanner offre tabelle integrate che archiviano le 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 analizzare i problemi di rendimento. Ad esempio, puoi verificare se sono presenti transazioni con esecuzione lenta che potrebbero influire sulle prestazioni o sulle query al secondo (QPS) nel database. Un altro scenario è quando le applicazioni client riscontrano un'elevata latenza di esecuzione delle transazioni. L'analisi delle statistiche sulle transazioni può aiutare a scoprire potenziali colli di bottiglia, come grandi volumi di aggiornamenti di una determinata colonna, che potrebbero influire sulla latenza.
Disponibilità
I dati di SPANNER_SYS
sono disponibili solo tramite le interfacce SQL; ad esempio:
Pagina Spanner Studio di un database nella console Google Cloud
Il comando
gcloud spanner databases execute-sql
Dashboard Approfondimenti sulle transazioni
L'API
executeQuery
Altri metodi di lettura singola forniti da Spanner non supportano SPANNER_SYS
.
Statistiche sulla latenza raggruppate per transazione
Le seguenti tabelle monitorano le statistiche relative alle transazioni che consumano risorse TOP
durante un periodo di tempo specifico.
SPANNER_SYS.TXN_STATS_TOP_MINUTE
: statistiche delle transazioni aggregate in intervalli di 1 minuto.SPANNER_SYS.TXN_STATS_TOP_10MINUTE
: statistiche sulle transazioni aggregate per intervalli di 10 minuti.SPANNER_SYS.TXN_STATS_TOP_HOUR
: statistiche delle transazioni aggregate in intervalli di 1 ora.
Queste tabelle hanno le seguenti proprietà:
Ogni tabella contiene dati per intervalli di tempo non sovrapposti della lunghezza specificata dal nome della tabella.
Gli intervalli si basano sulle ore dell'orologio. Gli intervalli di 1 minuto terminano al minuto, gli intervalli di 10 minuti terminano ogni 10 minuti a partire dall'ora e gli intervalli di 1 ora terminano all'ora.
Ad esempio, alle 11:59:30, gli intervalli più recenti disponibili per le query SQL sono:
- 1 minuto: 11:58:00-11:58:59
- 10 minuti: 11:40:00-11:49:59
- 1 ora: 10:00:00-10:59:59
Spanner raggruppa le statistiche in base a Fprint (impronta) delle transazioni. Se è presente un tag transazioni, Fprint è l'hash del tag. In caso contrario, si tratta dell'hash calcolato in base alle operazioni coinvolte nella transazione.
Poiché le statistiche vengono raggruppate in base a Fprint, se la stessa transazione viene eseguita più volte in un intervallo di tempo, in queste tabelle viene comunque visualizzata una sola voce relativa a questa transazione.
Ogni riga contiene statistiche per tutte le esecuzioni di una determinata transazione per cui Spanner acquisisce le statistiche durante l'intervallo specificato.
Se Spanner non è in grado di archiviare le statistiche per tutte le transazioni eseguite durante l'intervallo in queste tabelle, il sistema dà la priorità alle transazioni con la latenza più alta, i tentativi di commit e i byte scritti durante l'intervallo specificato.
Schema tabella
Nome colonna | Tipo | Descrizione |
---|---|---|
INTERVAL_END |
TIMESTAMP |
Fine dell'intervallo di tempo in cui si sono verificate le esecuzioni delle transazioni incluse. |
TRANSACTION_TAG |
STRING |
Il tag facoltativo della transazione per questa operazione di transazione. Per ulteriori informazioni sull'utilizzo dei tag, consulta la sezione Risoluzione dei problemi con i tag di transazione. Le statistiche per più transazioni con la stessa stringa tag sono raggruppate in una singola riga con "TRANSACTION_TAG" che corrisponde alla stringa tag. |
FPRINT |
INT64 |
L'hash di 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 modifiche in tempo reale, se la transazione riguarda le scritture nelle colonne e nelle tabelle controllate da un flusso di modifiche, WRITE_CONSTRUCTIVE_COLUMNS
conterrà due colonne: .data e ._exists
1, precedute dal nome del flusso di modifiche.
|
WRITE_DELETE_TABLES |
ARRAY<STRING> |
L'insieme di tabelle in cui sono presenti righe eliminate o sostituite dalla transazione. |
ATTEMPT_COUNT |
INT64 |
Numero totale di tentativi di transazione, inclusi i tentativi interrotti prima di chiamare il metodo "commit". |
COMMIT_ATTEMPT_COUNT |
INT64 |
Numero totale di tentativi di commit della transazione. Deve corrispondere al numero
di chiamate al metodo commit della transazione.
|
COMMIT_ABORT_COUNT |
INT64 |
Numero totale di tentativi di transazione interrotti, inclusi quelli
interrotti prima della chiamata del metodo commit
della transazione.
|
COMMIT_RETRY_COUNT |
INT64 |
Numero totale di tentativi ripetuti da quelli precedentemente interrotti. È possibile provare più volte una transazione Spanner prima che venga eseguita il commit a causa di conflitti del blocco o eventi temporanei. Un numero elevato di nuovi tentativi rispetto ai tentativi di commit indica che potrebbero esserci problemi che vale la pena esaminare. Per maggiori informazioni, consulta Informazioni sulle transazioni e sui conteggi di commit in questa pagina. |
COMMIT_FAILED_PRECONDITION_COUNT |
INT64 |
Numero totale di tentativi di commit della transazione che hanno restituito errori di precondizione non riusciti, ad esempio UNIQUE violazioni dell'indice, riga già esistente, riga non trovata
e così via.
|
AVG_PARTICIPANTS |
FLOAT64 |
Numero medio di partecipanti in ogni tentativo di commit. Per scoprire di più sui partecipanti, consulta Life di letture e scritture di Cloud Spanner. |
AVG_TOTAL_LATENCY_SECONDS |
FLOAT64 |
Media di secondi dalla prima operazione della transazione al commit o all'interruzione. |
AVG_COMMIT_LATENCY_SECONDS |
FLOAT64 |
Media di secondi impiegati 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 di commit totale, ovvero il tempo trascorso dall'ora di inizio della prima operazione transazionale all'ora di commit o di interruzione per tutti i tentativi di una transazione.
Se una transazione viene interrotta più volte e poi viene eseguita il commit, la latenza viene misurata per ogni tentativo fino al commit finale riuscito. I valori sono misurati in secondi.
L'array contiene un singolo elemento e ha il seguente tipo:
Per calcolare la latenza del percentile desiderato dalla distribuzione,
utilizza la funzione Per ulteriori informazioni, consulta Percentile e metriche con valore di distribuzione. |
OPERATIONS_BY_TABLE |
ARRAY<STRUCT> |
Impatto delle operazioni
Questa colonna consente di visualizzare il carico sulle tabelle e fornisce insight sulla frequenza di scrittura di una transazione 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, lo strumento a riga di comando gcloud
o la console Google Cloud.
Elenca le statistiche di base per ciascuna transazione in un determinato periodo di tempo
La seguente query restituisce i dati non elaborati per le principali transazioni del 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 query
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 |
Elenca le transazioni con la latenza media di commit più alta
La seguente query restituisce le transazioni con latenza media del commit elevata dell'ora precedente, ordinate dalla latenza media più alta alla 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 query
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 |
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 1 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 query
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 |
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 query
Fprint | read_columns | write_constructive_columns | 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 cui Spanner ha acquisito le statistiche in un determinato periodo di tempo:
SPANNER_SYS.TXN_STATS_TOTAL_MINUTE
: statistiche aggregate per tutte le transazioni durante 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 a intervalli di un'ora
Le tabelle delle statistiche aggregate hanno le seguenti proprietà:
Ogni tabella contiene dati per intervalli di tempo non sovrapposti della lunghezza specificata dal nome della tabella.
Gli intervalli sono basati sulle ore di orologio. Gli intervalli di 1 minuto terminano al minuto, gli intervalli di 10 minuti terminano ogni 10 minuti a partire dall'ora e gli intervalli di 1 ora terminano all'ora.
Ad esempio, alle 11:59:30, gli intervalli più recenti disponibili per le query SQL sulle statistiche aggregate delle transazioni sono:
- 1 minuto: 11:58:00-11:58:59
- 10 minuti: 11:40:00-11:49:59
- 1 ora: 10:00:00-10:59:59
Ogni riga contiene statistiche per tutte le transazioni eseguite nel database durante l'intervallo specificato, aggregate. C'è 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:
- Conteggio tentativi di commit
- Conteggio nuovi tentativi di commit
- Partecipanti alla transazione
- Latenze transazione
- Byte scritti
Per saperne di più, consulta la sezione 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 tentativi di transazione, inclusi i tentativi interrotti prima di chiamare il metodo "commit". |
COMMIT_ATTEMPT_COUNT |
INT64 |
Numero totale di tentativi di commit della transazione. Deve corrispondere al numero
di chiamate al metodo commit della transazione.
|
COMMIT_ABORT_COUNT |
INT64 |
Numero totale di tentativi di transazione interrotti, inclusi quelli
interrotti prima della chiamata del metodo commit
della transazione. |
COMMIT_RETRY_COUNT |
INT64 |
Numero di tentativi di commit ripetuti da tentativi precedentemente interrotti. È possibile che una transazione Spanner sia stata tentata più volte prima del commit a causa di contese del blocco o eventi temporanei. Un numero elevato di nuovi tentativi rispetto ai tentativi di commit indica che potrebbero esserci problemi che vale la pena esaminare. Per maggiori informazioni, consulta Informazioni sulle transazioni e sui conteggi di commit in questa pagina. |
COMMIT_FAILED_PRECONDITION_COUNT |
INT64 |
Numero totale di tentativi di commit della transazione che hanno restituito errori di precondizione non riusciti, ad esempio UNIQUE violazioni dell'indice, riga già esistente, riga non trovata
e così via.
|
AVG_PARTICIPANTS |
FLOAT64 |
Numero medio di partecipanti in ogni tentativo di commit. Per scoprire di più sui partecipanti, consulta Life di letture e scritture di Cloud Spanner. |
AVG_TOTAL_LATENCY_SECONDS |
FLOAT64 |
Media di secondi dalla prima operazione della transazione al commit o all'interruzione. |
AVG_COMMIT_LATENCY_SECONDS |
FLOAT64 |
Media di secondi impiegati 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 di commit totale, ovvero il tempo trascorso dall'ora di inizio della prima operazione transazionale all'ora di commit o interruzione per tutti i tentativi della transazione.
Se una transazione viene interrotta più volte e poi viene eseguito il commit, la latenza viene misurata per ogni tentativo fino al commit finale riuscito. I valori sono misurati in secondi.
L'array contiene un singolo elemento e ha il seguente tipo:
Per calcolare la latenza del percentile desiderato dalla distribuzione,
utilizza la funzione Per ulteriori informazioni, consulta Percentile e metriche con valore di distribuzione. |
OPERATIONS_BY_TABLE |
ARRAY<STRUCT> |
Impatto delle operazioni
Questa colonna consente di visualizzare il carico sulle tabelle e fornisce insight sulla frequenza di scrittura delle transazioni 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, lo strumento a riga di comando gcloud
o la console Google Cloud.
Trovare il numero totale di tentativi di commit per una transazione
La seguente query restituisce il numero totale di tentativi di commit per tutte le transazioni nell'intervallo completo di 1 minuto 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 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 contengono una sola voce per interval_end
per qualsiasi durata.
Trova la latenza di commit totale in tutte le transazioni
La seguente query restituisce la latenza di commit totale in tutte le transazioni nei 10 minuti precedenti:
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 query
total_commit_latency_hours |
---|
0.8967 |
Tieni presente che il risultato contiene una sola riga perché le statistiche aggregate contengono una sola voce per interval_end
per qualsiasi durata.
Trovare la latenza del 99° percentile per le transazioni
La seguente query restituisce la latenza del 99° percentile per le transazioni eseguite nei 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 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 al 99° percentile aiuta a identificare possibili transazioni outlier con latenza elevata.
Nel risultato è presente una sola riga perché le statistiche aggregate contengono una sola voce per interval_end
per qualsiasi durata.
Conservazione dei dati
Spanner conserva i dati di ogni tabella come minimo per i seguenti periodi di tempo:
SPANNER_SYS.TXN_STATS_TOP_MINUTE
eSPANNER_SYS.TXN_STATS_TOTAL_MINUTE
: intervalli relativi alle 6 ore precedenti.SPANNER_SYS.TXN_STATS_TOP_10MINUTE
eSPANNER_SYS.TXN_STATS_TOTAL_10MINUTE
: intervalli relativi ai 4 giorni precedenti.SPANNER_SYS.TXN_STATS_TOP_HOUR
eSPANNER_SYS.TXN_STATS_TOTAL_HOUR
: intervalli relativi ai 30 giorni precedenti.
Le statistiche sulle transazioni in Spanner forniscono insight sull'utilizzo del database da parte di un'applicazione e sono utili per analizzare i problemi di prestazioni. Ad esempio, puoi verificare se ci sono transazioni con esecuzione lenta che potrebbero causare contesa oppure identificare potenziali origini di carichi elevati, come grandi volumi di aggiornamenti per una determinata colonna. Seguendo i passaggi riportati di seguito, ti mostreremo come utilizzare le statistiche delle transazioni per esaminare le controversie nel database.
Comprendere le transazioni e i conteggi di commit
Potrebbe essere necessario provare più volte una transazione Spanner prima di eseguire il commit. Questo accade più di frequente quando due transazioni tentano di funzionare contemporaneamente sugli stessi dati e una delle transazioni deve essere interrotta per preservare la proprietà di isolamento della transazione. Alcuni altri eventi temporanei che possono causare l'interruzione di una transazione includono:
Problemi di rete temporanei.
Modifiche allo schema di database applicate mentre è in corso il processo di commit di una transazione.
L'istanza Spanner non ha la capacità per gestire tutte le richieste che riceve.
In questi scenari, un client deve riprovare la transazione interrotta fino a quando il commit non va a buon fine o si verifica un timeout. Per gli utenti delle librerie client ufficiali di Spanner, ogni libreria ha implementato un meccanismo automatico di nuovo tentativo. Se utilizzi una versione personalizzata del codice client, aggrega i commit della transazione in un loop di nuovi tentativi.
Una transazione Spanner può essere interrotta anche a causa di un errore non irreversibile, come un timeout della transazione, problemi di autorizzazione o un nome di tabella/colonna non valido. Non è necessario riprovare a eseguire queste transazioni e la libreria client di Spanner restituirà l'errore immediatamente.
La seguente tabella descrive alcuni esempi di come COMMIT_ATTEMPT_COUNT
,
COMMIT_ABORT_COUNT
e COMMIT_RETRY_COUNT
vengono registrati in diversi scenari.
Scenario | COMMIT_ATTEMPT_COUNT | COMMIT_ABORT_COUNT | COMMIT_RETRY_COUNT |
---|---|---|---|
Impegno della transazione completato 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 commit eseguito correttamente dopo un nuovo tentativo. | 2 | 1 | 1 |
In un intervallo di 10 minuti vengono eseguite 5 transazioni con lo stesso Fprint. Il commit di 3 transazioni è stato eseguito correttamente al primo tentativo, mentre il commit di 2 è stato interrotto e il commit di 2 è stato eseguito correttamente al primo tentativo. | 7 | 2 | 2 |
I dati nelle tabelle delle statistiche sulle transazioni sono dati aggregati per un intervallo di tempo. Per un determinato intervallo, è possibile che una transazione venga interrotta e nuovo tentativo avvenga intorno ai limiti e rientri in bucket diversi. Di conseguenza, in un determinato intervallo di tempo, i tentativi di interruzione e di nuovo tentativo potrebbero non corrispondere.
Queste statistiche sono pensate per la risoluzione dei problemi e l'introspezione e non è garantito che siano precise al 100%. Le statistiche vengono aggregate in memoria prima di essere archiviate nelle tabelle Cloud Spanner. Durante un upgrade o altre attività di manutenzione, i server Cloud Spanner possono essere riavviati, influenzando la precisione dei numeri.
Risolvere i conflitti dei database utilizzando le statistiche delle transazioni
Puoi utilizzare il codice SQL o la dashboard Transaction Insights per visualizzare le transazioni nel database che potrebbero causare elevate latenza a causa di conflitti del blocco.
I seguenti argomenti mostrano come esaminare tali transazioni utilizzando il codice SQL.
Seleziona un periodo di tempo per l'indagine
Puoi trovarlo nell'applicazione che utilizza Spanner.
Ai fini di questa esercitazione, supponiamo che il problema si sia verificato circa alle 17:20 del 17 maggio 2020.
Puoi utilizzare i tag transazione per identificare l'origine della transazione e correlare tra la tabella delle statistiche delle transazioni e le tabelle delle statistiche di blocco per una efficace risoluzione dei problemi relativi alla contesa dei blocchi. Per saperne di più, consulta la sezione Risoluzione dei problemi con i tag di transazione.
Raccogli le statistiche sulle transazioni per il periodo di tempo selezionato
Per iniziare l'indagine, eseguiremo una query sulla tabella TXN_STATS_TOTAL_10MINUTE
all'inizio del problema. I risultati di questa query ci mostreranno come la latenza e altre statistiche delle transazioni sono cambiate in quel periodo di tempo.
Ad esempio, la seguente query restituisce le statistiche aggregate delle transazioni
da 4:30 pm
a 7:40 pm
(inclusi).
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;
Nella tabella seguente sono elencati dati di esempio restituiti dalla nostra query.
interval_end | avg_total_latency_seconds | commit_attempt_count | commit_abort_count |
---|---|---|---|
17-05-2020 16:40:00-07:00 | 0,0284 | 315691 | 5170 |
17-05-2020 16:50:00-07:00 | 0,0250 | 302124 | 3828 |
17-05-2020 17:00:00-07:00 | 0,0460 | 346087 | 11382 |
17-05-2020 17:10:00-07:00 | 0,0864 | 379964 | 33826 |
17-05-2020 17:20:00-07:00 | 0,1291 | 390343 | 052549 |
17-05-2020 17:30:00-07:00 | 0,1314 | 456455 | 76392 |
17-05-2020 17:40:00-07:00 | 0,1598 | 507774 | 121.458 |
17-05-2020 17:50:00-07:00 | 0,1641 | 516587 | 115.875 |
17-05-2020 18:00:00-07:00 | 0,1578 | 552711 | 122.626 |
17-05-2020 18:10:00-07:00 | 0,1750 | 569460 | 154205 |
17-05-2020 18:20:00-07:00 | 0,1727 | 613571 | 160772 |
17-05-2020 18:30:00-07:00 | 0.1588 | 601994 | 143044 |
17-05-2020 18:40:00-07:00 | 0,2025 | 604211 | 170019 |
17-05-2020 18:50:00-07:00 | 0.1615 | 601622 | 135601 |
17-05-2020 19:00:00-07:00 | 0,1653 | 596804 | 129.511 |
17-05-2020 19:10:00-07:00 | 0,1414 | 560023 | 112.247 |
17-05-2020 19:20:00-07:00 | 0,1367 | 570864 | 100.596 |
17-05-2020 19:30:00-07:00 | 0,0894 | 539729 | 65316 |
17-05-2020 19:40:00-07:00 | 0.0820 | 479151 | 40398 |
Qui vediamo che la latenza aggregata e il conteggio delle interruzioni sono più elevati nei periodi evidenziati. Possiamo scegliere qualsiasi intervallo di 10 minuti in cui la latenza aggregata
e/o il conteggio delle interruzioni sono elevati. Scegliamo l'intervallo che termina a
2020-05-17T18:40:00
e lo utilizziamo nel passaggio successivo per identificare quali transazioni
contribuiscono a un'elevata latenza e al conteggio delle interruzioni.
Identifica le transazioni che presentano un'elevata latenza
Eseguiamo ora una query nella tabella TXN_STATS_TOP_10MINUTE
per l'intervallo selezionato nel passaggio precedente. Utilizzando questi dati, possiamo iniziare a identificare le transazioni che presentano un'elevata latenza e/o un numero di interruzioni elevato.
Esegui la seguente query per visualizzare le transazioni che incidono maggiormente sulle prestazioni in ordine decrescente di latenza totale per l'intervallo di esempio che termina a 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 |
---|---|---|---|---|---|---|
17-05-2020 18:40:00-07:00 | 15185072816865185658 | 0,3508 | 0,0139 | 278802 | 142.205 | 129.884 |
17-05-2020 18:40:00-07:00 | 15435530087434255496 | 0,1633 | 0,0142 | 129012 | 27177 | 24559 |
17-05-2020 18:40:00-07:00 | 14175643543447671202 | 0,1423 | 0,0133 | 5357 | 636 | 433 |
17-05-2020 18:40:00-07:00 | 898069986622520747 | 0,0198 | 0,0158 | 6 | 0 | 0 |
17-05-2020 18:40:00-07:00 | 10510121182038036893 | 0.0168 | 0,0125 | 7 | 0 | 0 |
17-05-2020 18:40:00-07:00 | 9287748709638024175 | 0,0159 | 0,0118 | 4269 | 1 | 0 |
17-05-2020 18:40:00-07:00 | 7129109266372596045 | 0,0142 | 0,0102 | 182227 | 0 | 0 |
17-05-2020 18:40:00-07:00 | 15630228555662391800 | 0.0120 | 0.0107 | 58 | 0 | 0 |
17-05-2020 18:40:00-07:00 | 7907238229716746451 | 0,0108 | 0,0097 | 65 | 0 | 0 |
17-05-2020 18:40:00-07:00 | 10158167220149989178 | 0,0095 | 0,0047 | 3454 | 0 | 0 |
17-05-2020 18:40:00-07:00 | 9353100217060788102 | 0,0093 | 0,0045 | 725 | 0 | 0 |
17-05-2020 18:40:00-07:00 | 9521689070912159706 | 0,0093 | 0,0045 | 164 | 0 | 0 |
17-05-2020 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 un'elevata latenza a causa di un numero elevato di interruzioni del commit. Possiamo anche vedere un numero elevato di nuovi tentativi del commit, il che indica che i commit interrotti sono stati successivamente riprovati. Nel prossimo passaggio, esamineremo ulteriormente la causa del problema.
Identifica le colonne coinvolte in una transazione che presenta un'elevata latenza
In questo passaggio, verificheremo se le transazioni ad alta latenza funzionano sullo
stesso insieme di colonne recuperando i dati di read_columns
, write_constructive_columns
e
write_delete_tables
per le transazioni con un numero di interruzioni 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 | 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] |
[] |
Come mostra l'output nella tabella precedente, le transazioni con la latenza totale media più alta leggono le stesse colonne. Possiamo anche osservare alcune contese di scrittura poiché le transazioni scrivono nella stessa colonna, ovvero TestHigherLatency._exists
.
Determinare le variazioni nel rendimento delle transazioni nel tempo
Possiamo vedere come le statistiche associate a questa forma di transazione sono cambiate nel corso di un periodo di tempo. Utilizza la query seguente, dove $FPrint rappresenta 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 |
---|---|---|---|---|---|---|---|
17-05-2020 16:40:00-07:00 | 0,095 | 0,010 | 53230 | 4752 | 4330 | 0 | 91 |
17-05-2020 16:50:00-07:00 | 0.069 | 0,009 | 61264 | 3589 | 3364 | 0 | 91 |
17-05-2020 17:00:00-07:00 | 0,150 | 0,010 | 75868 | 10557 | 9322 | 0 | 91 |
17-05-2020 17:10:00-07:00 | 0.248 | 0.013 | 103151 | 30220 | 28483 | 0 | 91 |
17-05-2020 17:20:00-07:00 | 0,310 | 0,012 | 130078 | 45655 | 41966 | 0 | 91 |
17-05-2020 17:30:00-07:00 | 0.294 | 0,012 | 160064 | 64930 | 59933 | 0 | 91 |
17-05-2020 17:40:00-07:00 | 0,315 | 0.013 | 209614 | 104949 | 96770 | 0 | 91 |
17-05-2020 17:50:00-07:00 | 0.322 | 0,012 | 215682 | 100408 | 95867 | 0 | 90 |
17-05-2020 18:00:00-07:00 | 0,310 | 0,012 | 230932 | 106728 | 99462 | 0 | 91 |
17-05-2020 18:10:00-07:00 | 0.309 | 0,012 | 259645 | 131049 | 125889 | 0 | 91 |
17-05-2020 18:20:00-07:00 | 0,315 | 0.013 | 272171 | 137910 | 129411 | 0 | 90 |
17-05-2020 18:30:00-07:00 | 0,292 | 0.013 | 258944 | 121475 | 115844 | 0 | 91 |
17-05-2020 18:40:00-07:00 | 0,350 | 0.013 | 278802 | 142205 | 134229 | 0 | 91 |
17-05-2020 18:50:00-07:00 | 0,302 | 0.013 | 256259 | 115626 | 109756 | 0 | 91 |
17-05-2020 19:00:00-07:00 | 0,315 | 0.014 | 250560 | 110662 | 100322 | 0 | 91 |
17-05-2020 19:10:00-07:00 | 0.271 | 0.014 | 238384 | 99025 | 90187 | 0 | 91 |
17-05-2020 19:20:00-07:00 | 0.273 | 0.014 | 219687 | 84019 | 79874 | 0 | 91 |
17-05-2020 19:30:00-07:00 | 0.198 | 0.013 | 195357 | 59370 | 55909 | 0 | 91 |
17-05-2020 19:40:00-07:00 | 0,181 | 0.013 | 167514 | 35705 | 32885 | 0 | 91 |
Nell'output sopra riportato possiamo osservare che la latenza totale è elevata per il periodo di tempo evidenziato. Inoltre, ovunque la latenza totale sia elevata, anche commit_attempt_count
commit_abort_count
e commit_retry_count
sono elevati, anche se la latenza dell'impegno (commit_latency
) non è cambiata molto. Poiché i commit delle transazioni vengono interrotti più spesso, i tentativi di commit sono alti anche a causa dei nuovi tentativi del commit.
Conclusione
In questo esempio, abbiamo visto che un numero elevato di interruzioni del commit è stato la causa di un'elevata latenza. 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, vediamo che l'applicazione ha effettivamente modificato il proprio carico di lavoro durante questo periodo di tempo, ad esempio è stato visualizzato un altro tipo di transazione con un valore elevato di attempts_per_second
e che la transazione diversa (ad esempio un job di pulizia notturna) era responsabile di ulteriori conflitti di blocco.
Identificare le transazioni non ritentate correttamente
La seguente query restituisce le transazioni campionate negli ultimi dieci minuti con un numero elevato di interruzioni del commit, ma nessun nuovo tentativo.
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 notare che la transazione con fprint 1557557373282541312 è stata interrotta 44232 volte, ma non è mai stata ripetuta. Sembra sospetto perché il numero di interruzioni è elevato ed è improbabile che ogni interruzione sia causata da un errore non irreversibile. D'altra parte, per la transazione con fprint 5776062322886969344, è meno sospetta perché il numero totale di interruzioni non è così alto.
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, in cui la logica di nuovo tentativo può essere esaminata 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 | write_constructive_columns | 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 nella 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 aiutare a determinare se il meccanismo di ripetizione della transazione implementato nella libreria client personalizzata funziona come previsto.
Passaggi successivi
- Scopri altri strumenti di introspezione.
- Scopri altre informazioni memorizzate da Spanner per ogni database nelle tabelle di schema di informazioni del database.
- Scopri di più sulle best practice SQL per Spanner.
- Scopri di più su come indagare su un utilizzo elevato della CPU.