Spanner proporciona tablas integradas que almacenan estadísticas sobre las transacciones. Puedes obtener estadísticas de estas tablas SPANNER_SYS.TXN_STATS*
mediante instrucciones SQL.
Cuándo usar las estadísticas de transacciones
Las estadísticas de transacciones son útiles para investigar problemas de rendimiento. Por ejemplo, puedes comprobar si hay transacciones lentas que puedan afectar al rendimiento o a las consultas por segundo (QPS) de tu base de datos. Otro escenario es cuando las aplicaciones cliente experimentan una latencia de ejecución de transacciones alta. Analizar las estadísticas de las transacciones puede ayudar a descubrir posibles cuellos de botella, como grandes volúmenes de actualizaciones en una columna concreta, que podrían estar afectando a la latencia.
Acceder a las estadísticas de transacciones
.Spanner proporciona las estadísticas de transacciones de la tabla en el esquema SPANNER_SYS
. Puedes acceder a los datos de SPANNER_SYS
de las siguientes formas:
La página de Spanner Studio de una base de datos en la Google Cloud consola.
El comando
gcloud spanner databases execute-sql
.El panel de control Información útil sobre la transacción.
El método
executeSql
o el métodoexecuteStreamingSql
.
Los siguientes métodos de lectura única que proporciona Spanner no admiten SPANNER_SYS
:
- Realizar una lectura fuerte desde una sola fila o varias filas en una tabla.
- Realizar una lectura inactiva de una sola fila o varias filas en una tabla.
- Leer desde una sola fila o varias filas en un índice secundario.
Estadísticas de latencia agrupadas por transacción
En las siguientes tablas se registran las estadísticas de las transacciones que consumen recursos TOP
durante un periodo específico.
SPANNER_SYS.TXN_STATS_TOP_MINUTE
: estadísticas de transacciones agregadas en intervalos de 1 minuto.SPANNER_SYS.TXN_STATS_TOP_10MINUTE
: estadísticas de transacciones agregadas en intervalos de 10 minutos.SPANNER_SYS.TXN_STATS_TOP_HOUR
: estadísticas de transacciones agregadas en intervalos de 1 hora.
Estas tablas tienen las siguientes propiedades:
Cada tabla contiene datos de intervalos de tiempo no superpuestos de la duración que se especifica en el nombre de la tabla.
Los intervalos se basan en la hora del reloj. Los intervalos de 1 minuto terminan al minuto, los intervalos de 10 minutos terminan cada 10 minutos a partir de la hora en punto y los intervalos de 1 hora terminan a la hora en punto.
Por ejemplo, a las 11:59:30, los intervalos más recientes disponibles para las consultas SQL son los siguientes:
- 1 minuto: de 11:58:00 a 11:58:59
- 10 minutos: de 11:40:00 a 11:49:59
- 1 hora: de 10:00:00 a 10:59:59
Spanner agrupa las estadísticas por FPRINT (huella digital) de las transacciones. Si hay una etiqueta de transacción, FPRINT es el hash de la etiqueta. De lo contrario, es el hash calculado en función de las operaciones implicadas en la transacción.
Como las estadísticas se agrupan en función de FPRINT, si se ejecuta la misma transacción varias veces en cualquier intervalo de tiempo, solo veremos una entrada de esa transacción en estas tablas.
Cada fila contiene estadísticas de todas las ejecuciones de una transacción concreta de las que Spanner registra estadísticas durante el intervalo especificado.
Si Spanner no puede almacenar estadísticas de todas las transacciones realizadas durante el intervalo en estas tablas, el sistema prioriza las transacciones con la latencia, los intentos de confirmación y los bytes escritos más altos durante el intervalo especificado.
Todas las columnas de las tablas admiten valores nulos.
Esquema de tabla
Nombre de la columna | Tipo | Descripción |
---|---|---|
INTERVAL_END |
TIMESTAMP |
Fin del intervalo de tiempo en el que se produjeron las ejecuciones de transacciones incluidas. |
TRANSACTION_TAG |
STRING |
Etiqueta de transacción opcional de esta operación de transacción. Para obtener más información sobre el uso de etiquetas, consulta Solucionar problemas con etiquetas de transacción. Las estadísticas de varias transacciones que tienen la misma cadena de etiqueta se agrupan en una sola fila con el `TRANSACTION_TAG` que coincide con esa cadena de etiqueta. |
FPRINT |
INT64 |
El hash de TRANSACTION_TAG , si está presente. De lo contrario, el hash se calcula en función de las operaciones que se realicen en la transacción.
INTERVAL_END y FPRINT actúan conjuntamente como una clave única para estas tablas. |
READ_COLUMNS |
ARRAY<STRING> |
Conjunto de columnas que ha leído la transacción. |
WRITE_CONSTRUCTIVE_COLUMNS |
ARRAY<STRING> |
El conjunto de columnas que se han escrito de forma constructiva (es decir, a las que se han asignado nuevos valores) en la transacción.
En el caso de los flujos de cambios, si la transacción implica escrituras en columnas y tablas monitorizadas por un flujo de cambios, WRITE_CONSTRUCTIVE_COLUMNS
contendrá dos columnas: .data y ._exists
1, con el prefijo del nombre del flujo de cambios.
|
WRITE_DELETE_TABLES |
ARRAY<STRING> |
El conjunto de tablas cuyas filas se han eliminado o sustituido por la transacción. |
ATTEMPT_COUNT |
INT64 |
Número total de veces que se intenta realizar la transacción, incluidos los intentos que se abortan antes de llamar a `commit`. |
COMMIT_ATTEMPT_COUNT |
INT64 |
Número total de intentos de confirmación de transacciones. Debe coincidir con el número de llamadas al método commit de la transacción.
|
COMMIT_ABORT_COUNT |
INT64 |
Número total de intentos de transacción que se han abortado, incluidos los que se han abortado antes de llamar al método commit
de la transacción.
|
COMMIT_RETRY_COUNT |
INT64 |
Número total de intentos que son reintentos de intentos abortados anteriormente. Una transacción de Spanner se puede intentar varias veces antes de confirmarse debido a conflictos de bloqueo o eventos transitorios. Un número elevado de reintentos en relación con los intentos de confirmación indica que puede haber problemas que merezcan la pena investigar. Para obtener más información, consulta la sección Información sobre las transacciones y los recuentos de confirmaciones de esta página. |
COMMIT_FAILED_PRECONDITION_COUNT |
INT64 |
Número total de intentos de confirmación de transacciones que han devuelto errores de condición previa fallida, como infracciones de índice, la fila ya existe, no se ha encontrado la fila, etc.UNIQUE
|
AVG_PARTICIPANTS |
FLOAT64 |
Número medio de participantes en cada intento de confirmación. Para obtener más información sobre los participantes, consulta el artículo Cómo funcionan las lecturas y escrituras de Spanner. |
AVG_TOTAL_LATENCY_SECONDS |
FLOAT64 |
Tiempo medio en segundos que transcurre desde la primera operación de la transacción hasta la confirmación o la cancelación. |
AVG_COMMIT_LATENCY_SECONDS |
FLOAT64 |
Tiempo medio en segundos que se tarda en realizar la operación de confirmación. |
AVG_BYTES |
FLOAT64 |
Número medio de bytes escritos por la transacción. |
TOTAL_LATENCY_DISTRIBUTION |
ARRAY<STRUCT>
|
Un histograma de la latencia total de confirmación, que es el tiempo transcurrido desde la hora de inicio de la primera operación transaccional hasta la hora de confirmación o cancelación, en todos los intentos de una transacción.
Si una transacción se cancela varias veces y, después, se confirma correctamente, la latencia se mide en cada intento hasta que se confirma correctamente. Los valores se miden en segundos.
La matriz contiene un solo elemento y tiene el siguiente tipo:
Para calcular la latencia del percentil deseado a partir de la distribución, usa la Para obtener más información, consulta Métricas de percentiles y de distribución. |
OPERATIONS_BY_TABLE |
ARRAY<STRUCT> |
Impacto de las operaciones
Esta columna ayuda a visualizar la carga de las tablas y proporciona estadísticas sobre la velocidad a la que una transacción escribe en las tablas.
Especifica la matriz de la siguiente manera:
|
1 _exists
es un campo interno que se usa para comprobar si existe una fila determinada.
Consultas de ejemplo
En esta sección se incluyen varios ejemplos de instrucciones SQL que obtienen estadísticas de transacciones. Puedes ejecutar estas instrucciones SQL mediante las bibliotecas de cliente, gcloud spanner o la Google Cloud consola.
Lista las estadísticas básicas de cada transacción en un periodo determinado.
La siguiente consulta devuelve los datos sin procesar de las transacciones principales del 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);
Salida de la 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 |
Lista de las transacciones con la latencia de confirmación media más alta
La siguiente consulta devuelve las transacciones con una latencia de confirmación media alta en la hora anterior, ordenadas de mayor a menor latencia de confirmación media.
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;
Salida de la 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 |
Buscar la latencia media de las transacciones que leen determinadas columnas
La siguiente consulta devuelve la información de latencia media de las transacciones que leen la columna ADDRESS de las estadí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;
Salida de la 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 |
Lista de transacciones por el número medio de bytes modificados
La siguiente consulta devuelve las transacciones muestreadas en la última hora, ordenadas por el número medio de bytes modificados por la transacción.
SELECT fprint,
read_columns,
write_constructive_columns,
write_delete_tables,
avg_bytes
FROM spanner_sys.txn_stats_top_hour
ORDER BY avg_bytes DESC;
Salida de la consulta
fprint | read_columns | write_constructive_columns | write_delete_tables | avg_bytes |
---|---|---|---|---|
40015598317 |
[] |
[] |
["Users"] |
25286 |
77848338483 |
[] |
[] |
["Cars", "Routes"] |
12005 |
20524969030 |
["ID", "ADDRESS"] |
[] |
["Users"] |
10923 |
Estadísticas agregadas
SPANNER_SYS
también contiene tablas para almacenar datos agregados de todas las transacciones de las que Spanner ha recogido estadísticas en un periodo específico:
SPANNER_SYS.TXN_STATS_TOTAL_MINUTE
: estadísticas agregadas de todas las transacciones durante intervalos de 1 minuto.SPANNER_SYS.TXN_STATS_TOTAL_10MINUTE
: estadísticas agregadas de todas las transacciones durante intervalos de 10 minutos.SPANNER_SYS.TXN_STATS_TOTAL_HOUR
: estadísticas agregadas de todas las transacciones durante intervalos de 1 hora.
Las tablas de estadísticas agregadas tienen las siguientes propiedades:
Cada tabla contiene datos de intervalos de tiempo no superpuestos de la duración que se especifica en el nombre de la tabla.
Los intervalos se basan en la hora del reloj. Los intervalos de 1 minuto terminan en el minuto, los intervalos de 10 minutos terminan cada 10 minutos a partir de la hora en punto y los intervalos de 1 hora terminan a la hora en punto.
Por ejemplo, a las 11:59:30, los intervalos más recientes disponibles para las consultas SQL sobre estadísticas de transacciones agregadas son los siguientes:
- 1 minuto: de 11:58:00 a 11:58:59
- 10 minutos: de 11:40:00 a 11:49:59
- 1 hora: de 10:00:00 a 10:59:59
Cada fila contiene estadísticas de todas las transacciones ejecutadas en la base de datos durante el intervalo especificado, agregadas. Solo hay una fila por intervalo de tiempo.
Las estadísticas recogidas en las tablas
SPANNER_SYS.TXN_STATS_TOTAL_*
pueden incluir transacciones que Spanner no haya recogido en las tablasSPANNER_SYS.TXN_STATS_TOP_*
.Algunas columnas de estas tablas se muestran como métricas en Cloud Monitoring. Las métricas expuestas son las siguientes:
- Número de intentos de confirmación
- Número de reintentos de confirmación
- Participantes de la transacción
- Latencias de las transacciones
- Bytes escritos
Para obtener más información, consulta Métricas de Spanner.
Esquema de tabla
Nombre de la columna | Tipo | Descripción |
---|---|---|
INTERVAL_END |
TIMESTAMP |
Hora de finalización del intervalo de tiempo en el que se ha recogido esta estadística. |
ATTEMPT_COUNT |
INT64 |
Número total de veces que se intenta realizar la transacción, incluidos los intentos que se abortan antes de llamar a `commit`. |
COMMIT_ATTEMPT_COUNT |
INT64 |
Número total de intentos de confirmación de transacciones. Debe coincidir con el número de llamadas al método commit de la transacción.
|
COMMIT_ABORT_COUNT |
INT64 |
Número total de intentos de transacción que se han abortado, incluidos los que se han abortado antes de llamar al método commit
de la transacción. |
COMMIT_RETRY_COUNT |
INT64 |
Número de intentos de confirmación que son reintentos de intentos anteriores cancelados. Es posible que se haya intentado realizar una transacción de Spanner varias veces antes de que se confirme debido a conflictos de bloqueo o eventos transitorios. Un número elevado de reintentos en relación con los intentos de confirmación indica que puede haber problemas que merezcan la pena investigar. Para obtener más información, consulta la sección Información sobre las transacciones y los recuentos de confirmaciones de esta página. |
COMMIT_FAILED_PRECONDITION_COUNT |
INT64 |
Número total de intentos de confirmación de transacciones que han devuelto errores de condición previa fallida, como infracciones de índice, la fila ya existe, no se ha encontrado la fila, etc.UNIQUE
|
AVG_PARTICIPANTS |
FLOAT64 |
Número medio de participantes en cada intento de confirmación. Para obtener más información sobre los participantes, consulta el artículo Cómo funcionan las lecturas y escrituras de Spanner. |
AVG_TOTAL_LATENCY_SECONDS |
FLOAT64 |
Tiempo medio en segundos que transcurre desde la primera operación de la transacción hasta la confirmación o la cancelación. |
AVG_COMMIT_LATENCY_SECONDS |
FLOAT64 |
Tiempo medio en segundos que se tarda en realizar la operación de confirmación. |
AVG_BYTES |
FLOAT64 |
Número medio de bytes escritos por la transacción. |
TOTAL_LATENCY_DISTRIBUTION |
ARRAY<STRUCT>
|
Un histograma de la latencia total de confirmación, que es el tiempo transcurrido desde la hora de inicio de la primera operación transaccional hasta la hora de confirmación o cancelación de todos los intentos de transacción.
Si una transacción se cancela varias veces y, después, se confirma correctamente, la latencia se mide en cada intento hasta que se confirma correctamente. Los valores se miden en segundos.
La matriz contiene un solo elemento y tiene el siguiente tipo:
Para calcular la latencia del percentil deseado a partir de la distribución, usa la Para obtener más información, consulta Métricas de percentiles y de distribución. |
OPERATIONS_BY_TABLE |
ARRAY<STRUCT> |
Impacto de las operaciones
Esta columna ayuda a visualizar la carga de las tablas y proporciona estadísticas sobre la velocidad a la que las transacciones escriben en las tablas.
Especifica la matriz de la siguiente manera:
|
Consultas de ejemplo
En esta sección se incluyen varios ejemplos de instrucciones SQL que obtienen estadísticas de transacciones. Puedes ejecutar estas instrucciones SQL mediante las bibliotecas de cliente, gcloud spanner o la Google Cloud consola.
Consulta el número total de intentos de confirmación de todas las transacciones.
La siguiente consulta devuelve el número total de intentos de confirmación de todas las transacciones del intervalo de 1 minuto completo más reciente:
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;
Salida de la consulta
interval_end | commit_attempt_count |
---|---|
2020-01-17 11:46:00-08:00 |
21 |
Ten en cuenta que solo hay una fila en el resultado porque las estadísticas agregadas solo tienen una entrada por interval_end
para cualquier periodo.
Buscar la latencia total de confirmación de todas las transacciones
La siguiente consulta devuelve la latencia total de confirmación de todas las transacciones de los ú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);
Salida de la consulta
total_commit_latency_hours |
---|
0.8967 |
Ten en cuenta que solo hay una fila en el resultado porque las estadísticas agregadas solo tienen una entrada por interval_end
para cualquier periodo.
Buscar la latencia del percentil 99 de las transacciones
La siguiente consulta devuelve la latencia del percentil 99 de las transacciones realizadas en los ú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;
Salida de la consulta
interval_end | avg_total_latency_seconds | percentile_latency |
---|---|---|
2022-08-17 11:46:00-08:00 |
0.34576998305986395 |
9.00296190476190476 |
Observa la gran diferencia entre la latencia media y la del percentil 99. La latencia del percentil 99 ayuda a identificar posibles transacciones atípicas con una latencia alta.
Solo hay una fila en el resultado porque las estadísticas agregadas solo tienen una entrada por interval_end
para cualquier periodo.
Conservación de datos
Como mínimo, Spanner conserva los datos de cada tabla durante los siguientes periodos:
SPANNER_SYS.TXN_STATS_TOP_MINUTE
ySPANNER_SYS.TXN_STATS_TOTAL_MINUTE
: intervalos que abarcan las 6 horas anteriores.SPANNER_SYS.TXN_STATS_TOP_10MINUTE
ySPANNER_SYS.TXN_STATS_TOTAL_10MINUTE
: intervalos que abarcan los 4 días anteriores.SPANNER_SYS.TXN_STATS_TOP_HOUR
ySPANNER_SYS.TXN_STATS_TOTAL_HOUR
: intervalos que abarcan los 30 días anteriores.
Las estadísticas de transacciones de Spanner proporcionan información valiosa sobre cómo usa una aplicación la base de datos y son útiles para investigar problemas de rendimiento. Por ejemplo, puede comprobar si hay transacciones lentas que puedan estar provocando conflictos o identificar posibles fuentes de carga elevada, como grandes volúmenes de actualizaciones en una columna concreta. Siguiendo los pasos que se indican a continuación, te mostraremos cómo usar las estadísticas de transacciones para investigar las contenciones de tu base de datos.
Información sobre las transacciones y los recuentos de confirmaciones
Es posible que una transacción de Spanner tenga que intentarse varias veces antes de confirmarse. Esto suele ocurrir cuando dos transacciones intentan trabajar con los mismos datos al mismo tiempo y una de las transacciones debe anularse para conservar la propiedad de aislamiento de la transacción. Otros eventos transitorios que también pueden provocar que se cancele una transacción:
Problemas de red transitorios.
Se aplican cambios en el esquema de la base de datos mientras se está confirmando una transacción.
La instancia de Spanner no tiene capacidad suficiente para gestionar todas las solicitudes que recibe.
En estos casos, un cliente debe volver a intentar la transacción cancelada hasta que se complete correctamente o se agote el tiempo de espera. Los usuarios de las bibliotecas de cliente oficiales de Spanner tienen un mecanismo de reintento automático implementado en cada biblioteca. Si usas una versión personalizada del código de cliente, envuelve las confirmaciones de transacciones en un bucle de reintento.
Una transacción de Spanner también puede anularse debido a un error no reintentable, como un tiempo de espera de la transacción, problemas de permisos o un nombre de tabla o columna no válido. No es necesario volver a intentar estas transacciones y la biblioteca de cliente de Spanner devolverá el error inmediatamente.
En la siguiente tabla se describen algunos ejemplos de cómo se registran COMMIT_ATTEMPT_COUNT
, COMMIT_ABORT_COUNT
y COMMIT_RETRY_COUNT
en diferentes situaciones.
Situación | COMMIT_ATTEMPT_COUNT | COMMIT_ABORT_COUNT | COMMIT_RETRY_COUNT |
---|---|---|---|
Transacción confirmada correctamente en el primer intento. | 1 | 0 | 0 |
Se ha cancelado la transacción debido a un error de tiempo de espera. | 1 | 1 | 0 |
Transacción anulada debido a un problema de red transitorio y confirmada correctamente después de un reintento. | 2 | 1 | 1 |
Se ejecutan 5 transacciones con la misma huella digital en un intervalo de 10 minutos. 3 de las transacciones se han confirmado correctamente en el primer intento, mientras que 2 transacciones se han cancelado y, después, se han confirmado correctamente en el primer reintento. | 7 | 2 | 2 |
Los datos de las tablas transactions-stats son datos agregados de un intervalo de tiempo. En un intervalo concreto, es posible que se produzca una cancelación de transacción y un reintento en los límites, y que se incluyan en diferentes contenedores. Por lo tanto, en un intervalo de tiempo concreto, es posible que las cancelaciones y los reintentos no sean iguales.
Estas estadísticas se han diseñado para solucionar problemas y hacer introspección, y no se garantiza que sean 100% precisas. Las estadísticas se agregan en la memoria antes de almacenarse en las tablas de Spanner. Durante una actualización u otras actividades de mantenimiento, los servidores de Spanner pueden reiniciarse, lo que afecta a la precisión de las cifras.
Solucionar problemas de contención de bases de datos mediante estadísticas de transacciones
Puedes usar código SQL o el panel de control Estadísticas de transacciones para ver las transacciones de tu base de datos que pueden provocar latencias altas debido a conflictos de bloqueo.
En los siguientes temas se muestra cómo investigar estas transacciones mediante código SQL.
Seleccionar un periodo para investigar
Puedes encontrarlo en la aplicación que usa Spanner.
Para este ejercicio, supongamos que el problema empezó a producirse alrededor de las 17:20 del 17 de mayo del 2020.
Puedes usar etiquetas de transacción para identificar la fuente de la transacción y establecer una correlación entre la tabla de estadísticas de transacciones y la tabla de estadísticas de bloqueos para solucionar problemas de contención de bloqueos de forma eficaz. Consulte más información en el artículo Solucionar problemas con etiquetas de transacción.
Recoger estadísticas de transacciones del periodo seleccionado
Para iniciar la investigación, consultaremos la tabla TXN_STATS_TOTAL_10MINUTE
en torno al momento en que se produjo el problema. Los resultados de esta consulta nos mostrarán cómo han cambiado la latencia y otras estadísticas de las transacciones durante ese periodo.
Por ejemplo, la siguiente consulta devuelve las estadísticas de transacciones agregadas del 4:30 pm
al 7:40 pm
(ambos incluidos).
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;
En la siguiente tabla se muestran datos de ejemplo devueltos por nuestra 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 |
Aquí vemos que la latencia agregada y el número de cancelaciones son mayores en los periodos destacados. Podemos elegir cualquier intervalo de 10 minutos en el que la latencia agregada o el número de cancelaciones sean altos. Vamos a elegir el intervalo que termina en 2020-05-17T18:40:00
y lo usaremos en el siguiente paso para identificar qué transacciones contribuyen a la alta latencia y al recuento de cancelaciones.
Identificar las transacciones que tienen una latencia alta
Ahora vamos a consultar la tabla TXN_STATS_TOP_10MINUTE
para obtener el intervalo que se ha seleccionado en el paso anterior. Con estos datos, podemos empezar a identificar qué transacciones tienen una latencia alta o un número elevado de cancelaciones.
Ejecuta la siguiente consulta para obtener las transacciones que más influyen en el rendimiento en orden descendente de latencia total para el intervalo de ejemplo que termina en 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 la primera fila (destacada) de la tabla anterior muestra una transacción con una latencia alta debido a un gran número de anulaciones de confirmación. También podemos ver un número elevado de reintentos de confirmación, lo que indica que se ha vuelto a intentar confirmar las confirmaciones anuladas. En el siguiente paso, investigaremos más a fondo para determinar la causa del problema.
Identificar las columnas implicadas en una transacción que experimenta una latencia alta
En este paso, comprobaremos si las transacciones con alta latencia operan en el mismo conjunto de columnas. Para ello, obtendremos los datos read_columns
, write_constructive_columns
y write_delete_tables
de las transacciones con un alto recuento de cancelaciones. El valor FPRINT
también te será útil en el siguiente paso.
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 se muestra en la tabla anterior, las transacciones con la latencia total media más alta leen las mismas columnas. También podemos observar algunas
disputas de escritura, ya que las transacciones escriben en la misma columna, es decir, TestHigherLatency._exists
.
Determinar cómo ha cambiado el rendimiento de las transacciones a lo largo del tiempo
Podemos ver cómo han cambiado las estadísticas asociadas a esta forma de transacción a lo largo de un periodo. Usa la siguiente consulta, donde $FPRINT es la huella digital de la transacción de alta latencia del paso 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 | latencia | 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 USD | 0,013 | 167514 | 35705 | 32885 | 0 | 91 |
En el resultado anterior, podemos observar que la latencia total es alta durante el periodo de tiempo destacado. Además, cuando la latencia total es alta, commit_attempt_count
commit_abort_count
y commit_retry_count
también lo son, aunque la latencia de confirmación (commit_latency
) no haya cambiado mucho. Como las confirmaciones de transacciones se cancelan con más frecuencia, los intentos de confirmación también son elevados debido a los reintentos de confirmación.
Conclusión
En este ejemplo, hemos visto que el alto recuento de anulaciones de confirmación era la causa de la alta latencia. El siguiente paso es consultar los mensajes de error de anulación de confirmación recibidos por la aplicación para saber el motivo de las anulaciones. Al inspeccionar los registros de la aplicación, vemos que la aplicación cambió su carga de trabajo durante este tiempo. Es decir, apareció otra forma de transacción con un attempts_per_second
alto y esa transacción diferente (quizá un trabajo de limpieza nocturno) fue la responsable de los conflictos de bloqueo adicionales.
Identificar las transacciones que no se han reintentado correctamente
La siguiente consulta devuelve las transacciones muestreadas en los últimos diez minutos que tienen un recuento de anulaciones de confirmación alto, pero no reintentos.
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 |
Hemos observado que la transacción con fprint 1557557373282541312 se ha cancelado 44232 veces, pero nunca se ha vuelto a intentar. Parece sospechoso porque el número de cancelaciones es alto y es poco probable que todas las cancelaciones se hayan debido a un error no reintentable. Por otro lado, la transacción con fprint 5776062322886969344 es menos sospechosa porque el número total de cancelaciones no es tan alto.
La siguiente consulta devuelve más detalles sobre la transacción con fprint 1557557373282541312,incluidos read_columns
, write_constructive_columns
y write_delete_tables
. Esta información ayuda a identificar la transacción en el código del cliente, donde se puede revisar la lógica de reintento de este caso.
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 |
Podemos ver que la transacción implica una lectura de la columna oculta Singers._exists
para comprobar si existe una fila. La transacción también escribe en las columnas Singers.FirstName
y Singer.LastName
. Esta información puede ayudarte a determinar si el mecanismo de reintento de transacciones implementado en tu biblioteca de cliente personalizada funciona correctamente.
Siguientes pasos
- Consulta información sobre otras herramientas de introspección.
- Consulta más información sobre los datos que almacena Spanner de cada base de datos en las tablas del esquema de información de la base de datos.
- Consulta más información sobre las prácticas recomendadas de SQL para Spanner.
- Consulta más información sobre cómo investigar el uso elevado de la CPU.