Spanner proporciona tablas integradas que almacenan estadísticas sobre transacciones. Puedes obtener estadísticas de estas tablas SPANNER_SYS.TXN_STATS*
mediante instrucciones de SQL.
Cuándo usar las estadísticas de transacciones
Las estadísticas de transacciones son útiles para investigar problemas de rendimiento. Por ejemplo, puedes verificar si hay transacciones que se ejecutan con lentitud y que podrían afectar el rendimiento o las consultas por segundo (QPS) en tu base de datos. Otro caso es cuando tus aplicaciones cliente experimentan una latencia alta en la ejecución de transacciones. Analizar las estadísticas de las transacciones puede ayudar a descubrir posibles cuellos de botella, como grandes volúmenes de actualizaciones en una columna en particular, que podrían estar afectando la latencia.
Accede 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 maneras:
La página de Spanner Studio de una base de datos en la consola de Google Cloud
El comando
gcloud spanner databases execute-sql
.El panel Estadísticas de transacciones
El método
executeSql
o el métodoexecuteStreamingSql
.
Los siguientes métodos de lectura única que proporciona Spanner no son compatibles con SPANNER_SYS
:
- Realizar una lectura sólida desde una o varias filas de una tabla
- Realizar una lectura inactiva desde una o varias filas en una tabla
- Leer desde una o varias filas en un índice secundario
Estadísticas de latencia agrupadas por transacción
En las siguientes tablas, se realiza un seguimiento de las estadísticas de las transacciones que consumen recursos TOP
durante un período 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 longitud que se especifica en el nombre de la tabla.
Los intervalos se basan en tiempos de reloj. Los intervalos de 1 minuto finalizan en el minuto, los intervalos de 10 minutos finalizan cada 10 minutos a partir de la hora y los intervalos de 1 hora finalizan en la hora.
Por ejemplo, a las 11:59:30 a.m., los intervalos más recientes disponibles para las consultas de SQL son los siguientes:
- 1 minuto: de 11:58:00 a 11:58:59 a.m.
- 10 minutos: de 11:40:00 a 11:49:59 a.m.
- 1 hora: de 10:00:00 a 10:59:59 a.m.
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 involucradas en la transacción.
Debido a que las estadísticas se agrupan según FPRINT, si la misma transacción se ejecuta varias veces dentro de cualquier intervalo de tiempo, aún veremos solo una entrada para esa transacción en estas tablas.
Cada fila contiene estadísticas de todas las ejecuciones de una transacción en particular que Spanner captura estadísticas durante el intervalo especificado.
Si Spanner no puede almacenar estadísticas de todas las transacciones ejecutadas durante el intervalo en estas tablas, el sistema prioriza las transacciones con la latencia más alta, los intentos de confirmación y los bytes escritos durante el intervalo especificado.
Todas las columnas de las tablas admiten valores nulos.
Esquema de la tabla
Nombre de la columna | Tipo | Descripción |
---|---|---|
INTERVAL_END |
TIMESTAMP |
Fin del intervalo en el que se produjeron las ejecuciones de transacciones incluidas. |
TRANSACTION_TAG |
STRING |
Es la etiqueta de transacción opcional para esta operación de transacción. Para obtener más información sobre el uso de etiquetas, consulta Solución de problemas con etiquetas de transacción. Las estadísticas de varias transacciones que tienen la misma cadena de etiquetas se agrupan en una sola fila con el valor `TRANSACTION_TAG` que coincide con esa cadena de etiquetas. |
FPRINT |
INT64 |
Es el hash del TRANSACTION_TAG si está presente. De lo contrario, el hash se calcula en función de las operaciones involucradas en la transacción.
INTERVAL_END y FPRINT juntos actúan como una clave única para estas tablas. |
READ_COLUMNS |
ARRAY<STRING> |
Es el conjunto de columnas que leyó la transacción. |
WRITE_CONSTRUCTIVE_COLUMNS |
ARRAY<STRING> |
Es el conjunto de columnas que la transacción escribió de manera constructiva (es decir, asignadas a valores nuevos).
En el caso de los flujos de cambios, si la transacción implicó escrituras en columnas y tablas supervisadas por un flujo de cambios, WRITE_CONSTRUCTIVE_COLUMNS
contendrá dos columnas: .data y ._exists
1, con el prefijo de un nombre de flujo de cambios.
|
WRITE_DELETE_TABLES |
ARRAY<STRING> |
El conjunto de tablas cuyas filas se borraron o reemplazaron mediante la transacción. |
ATTEMPT_COUNT |
INT64 |
Cantidad total de veces que se intenta la transacción, incluidos los intentos que se anulan antes de llamar a "commit". |
COMMIT_ATTEMPT_COUNT |
INT64 |
Cantidad total de intentos de confirmación de transacciones. Debe coincidir con la cantidad de llamadas al método commit de la transacción.
|
COMMIT_ABORT_COUNT |
INT64 |
Cantidad total de intentos de transacción que se anularon, incluidos los que se anularon antes de llamar al método commit de la transacción.
|
COMMIT_RETRY_COUNT |
INT64 |
Es la cantidad total de intentos que son reintentos de intentos anulados anteriormente. Es posible que una transacción de Spanner se intente varias veces antes de que se confirme debido a conflictos de bloqueo o eventos transitorios. Una gran cantidad de reintentos en relación con los intentos de confirmación indica que podría haber problemas que vale la pena investigar. Para obtener más información, consulta Información sobre las transacciones y los recuentos de confirmaciones en esta página. |
COMMIT_FAILED_PRECONDITION_COUNT |
INT64 |
Es la cantidad total de intentos de confirmación de transacciones que devolvieron errores de condición previa fallida, como incumplimientos del índice UNIQUE , la fila ya existe, no se encontró la fila, etcétera.
|
AVG_PARTICIPANTS |
FLOAT64 |
Cantidad promedio de participantes en cada intento de confirmación. Para obtener más información sobre los participantes, consulta Ciclo de vida de las operaciones de lectura y escritura de Spanner. |
AVG_TOTAL_LATENCY_SECONDS |
FLOAT64 |
Promedio de segundos tomados de la primera operación de la transacción para confirmar o anular |
AVG_COMMIT_LATENCY_SECONDS |
FLOAT64 |
Promedio de segundos necesarios para realizar la operación de confirmación. |
AVG_BYTES |
FLOAT64 |
Cantidad promedio de bytes que escribió la transacción. |
TOTAL_LATENCY_DISTRIBUTION |
ARRAY<STRUCT>
|
Es un histograma de la latencia total de confirmación, que es el tiempo transcurrido desde el inicio de la primera operación transaccional hasta el momento de confirmación o anulación, para todos los intentos de una transacción.
Si una transacción se anula varias veces y, luego, se confirma correctamente, se mide la latencia de cada intento hasta la confirmación final exitosa. Los valores se miden en segundos.
El array contiene un solo elemento y tiene el siguiente tipo:
Para calcular la latencia del percentil deseado a partir de la distribución, usa la función Para obtener más información, consulta Percentiles y métricas con valores de distribución. |
OPERATIONS_BY_TABLE |
ARRAY<STRUCT> |
Es el impacto de las operaciones
Esta columna ayuda a visualizar la carga en las tablas y proporciona estadísticas sobre la velocidad a la que una transacción escribe en las tablas.
Especifica el array de la siguiente manera:
|
1 _exists
es un campo interno que se usa para verificar si existe una fila determinada.
Consultas de ejemplo
Esta sección incluye varias instrucciones de SQL de ejemplo que recuperan estadísticas de transacciones. Puedes ejecutar estas instrucciones de SQL con las bibliotecas cliente, gcloud spanner o la consola deGoogle Cloud .
Enumera las estadísticas básicas de cada transacción en un período determinado
La siguiente consulta muestra los datos sin procesar de las transacciones principales en el 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);
Resultado 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 |
Enumera las transacciones con la latencia de confirmación promedio más alta
En la siguiente consulta, se muestran las transacciones con latencia de confirmación promedio alta en la hora anterior, ordenadas desde la latencia de confirmación promedio más alta a la más baja.
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;
Resultado 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 |
Encuentra la latencia promedio de las transacciones que leen ciertas columnas
En la siguiente consulta, se muestra la información de latencia promedio para 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;
Resultado 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 |
Enumera las transacciones según la cantidad promedio de bytes modificados
En la siguiente consulta, se observan las transacciones muestreadas en la última hora, ordenadas por la cantidad promedio 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;
Resultado 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 para las que Spanner capturó estadísticas en un período específico:
SPANNER_SYS.TXN_STATS_TOTAL_MINUTE
: agrega estadísticas para todas las transacciones durante intervalos de 1 minutoSPANNER_SYS.TXN_STATS_TOTAL_10MINUTE
: agrega estadísticas para todas las transacciones durante intervalos de 10 minutosSPANNER_SYS.TXN_STATS_TOTAL_HOUR
: agrega estadísticas para todas las transacciones durante intervalos de 1 hora
Las tablas conjuntas de estadísticas tienen las siguientes propiedades:
Cada tabla contiene datos de intervalos de tiempo no superpuestos de la longitud que se especifica en el nombre de la tabla.
Los intervalos se basan en tiempos de reloj. Los intervalos de 1 minuto finalizan en el minuto, los intervalos de 10 minutos finalizan cada 10 minutos a partir de la hora y los intervalos de 1 hora finalizan en la hora.
Por ejemplo, a las 11:59:30 a.m., los intervalos más recientes disponibles para las consultas de SQL sobre las estadísticas de transacciones agregadas son los siguientes:
- 1 minuto: de 11:58:00 a 11:58:59 a.m.
- 10 minutos: de 11:40:00 a 11:49:59 a.m.
- 1 hora: de 10:00:00 a 10:59:59 a.m.
Cada fila contiene estadísticas para todas las transacciones ejecutadas en la base de datos durante el intervalo especificado, combinadas. Solo hay una fila por intervalo de tiempo.
Las estadísticas capturadas en las tablas
SPANNER_SYS.TXN_STATS_TOTAL_*
pueden incluir transacciones que Spanner no capturó en las tablasSPANNER_SYS.TXN_STATS_TOP_*
.Algunas columnas de estas tablas se exponen como métricas en Cloud Monitoring. Las métricas expuestas son las siguientes:
- Recuento de intentos de confirmación
- Recuento de reintentos de confirmación
- Participantes de la transacción
- Latencias de transacciones
- Bytes escritos
Para obtener más información, consulta Métricas de Spanner.
Esquema de la tabla
Nombre de la columna | Tipo | Descripción |
---|---|---|
INTERVAL_END |
TIMESTAMP |
Fin del intervalo en el que se capturó esta estadística. |
ATTEMPT_COUNT |
INT64 |
Cantidad total de veces que se intentan las transacciones, incluidos los intentos que se anulan antes de llamar a "commit". |
COMMIT_ATTEMPT_COUNT |
INT64 |
Cantidad total de intentos de confirmación de transacciones. Debe coincidir con la cantidad de llamadas al método commit de la transacción.
|
COMMIT_ABORT_COUNT |
INT64 |
Cantidad total de intentos de transacción que se anularon, incluidos los que se anularon antes de llamar al método commit de la transacción. |
COMMIT_RETRY_COUNT |
INT64 |
Cantidad de intentos de confirmación que son reintentos de intentos anulados anteriormente. 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. Una gran cantidad de reintentos en relación con los intentos de confirmación indica que podría haber problemas que vale la pena investigar. Para obtener más información, consulta Información sobre las transacciones y los recuentos de confirmaciones en esta página. |
COMMIT_FAILED_PRECONDITION_COUNT |
INT64 |
Es la cantidad total de intentos de confirmación de transacciones que devolvieron errores de condición previa fallida, como incumplimientos del índice UNIQUE , la fila ya existe, no se encontró la fila, etcétera.
|
AVG_PARTICIPANTS |
FLOAT64 |
Cantidad promedio de participantes en cada intento de confirmación. Para obtener más información sobre los participantes, consulta Ciclo de vida de las operaciones de lectura y escritura de Spanner. |
AVG_TOTAL_LATENCY_SECONDS |
FLOAT64 |
Promedio de segundos tomados de la primera operación de la transacción para confirmar o anular |
AVG_COMMIT_LATENCY_SECONDS |
FLOAT64 |
Promedio de segundos necesarios para realizar la operación de confirmación. |
AVG_BYTES |
FLOAT64 |
Cantidad promedio de bytes que escribió la transacción. |
TOTAL_LATENCY_DISTRIBUTION |
ARRAY<STRUCT>
|
Es un histograma de la latencia total de confirmación, que es el tiempo transcurrido desde el inicio de la primera operación transaccional hasta el momento de confirmación o anulación de todos los intentos de transacción.
Si una transacción se anula varias veces y, luego, se confirma correctamente, se mide la latencia de cada intento hasta la confirmación final exitosa. Los valores se miden en segundos.
El array contiene un solo elemento y tiene el siguiente tipo:
Para calcular la latencia del percentil deseado a partir de la distribución, usa la función Para obtener más información, consulta Percentiles y métricas con valores de distribución. |
OPERATIONS_BY_TABLE |
ARRAY<STRUCT> |
Impacto de las operaciones
Esta columna ayuda a visualizar la carga en las tablas y proporciona estadísticas sobre la velocidad a la que las transacciones escriben en las tablas.
Especifica el array de la siguiente manera:
|
Consultas de ejemplo
Esta sección incluye varias instrucciones de SQL de ejemplo que recuperan estadísticas de transacciones. Puedes ejecutar estas instrucciones de SQL con las bibliotecas cliente, gcloud spanner o la consola deGoogle Cloud .
Encuentra la cantidad total de intentos de confirmación para todas las transacciones
En la siguiente consulta, se muestra la cantidad total de intentos de confirmación para todas las transacciones en el 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;
Resultado 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 tienen solo una entrada por interval_end
para cualquier duración de tiempo.
Busca la latencia de confirmación total en todas las transacciones
La siguiente consulta muestra la latencia de confirmación total en todas las transacciones de los 10 minutos anteriores:
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);
Resultado 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 tienen solo una entrada por interval_end
para cualquier duración de tiempo.
Cómo encontrar la latencia del percentil 99 para las transacciones
La siguiente consulta muestra la latencia del percentil 99 para las transacciones ejecutadas 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;
Resultado 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 promedio y la del percentil 99. La latencia del percentil 99 ayuda a identificar posibles transacciones atípicas con latencia alta.
Solo hay una fila en el resultado porque las estadísticas agregadas tienen solo una entrada por interval_end
para cualquier duración de tiempo.
Retención de datos
Como mínimo, Spanner conserva los datos para cada tabla durante los siguientes períodos:
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 en Spanner brindan información sobre cómo una aplicación usa la base de datos y son útiles para investigar problemas de rendimiento. Por ejemplo, puedes verificar si hay transacciones de ejecución lenta que podrían estar causando una contención, o puedes identificar posibles fuentes de carga alta, como grandes volúmenes de actualizaciones a una columna en particular. En los siguientes pasos, te mostraremos cómo usar las estadísticas de transacciones para investigar las relaciones en tu base de datos.
Acerca de las transacciones y los recuentos de confirmaciones
Es posible que una transacción de Spanner se deba probar varias veces antes de que se confirme. Esto ocurre con mayor frecuencia cuando dos transacciones intentan trabajar con los mismos datos al mismo tiempo y una de las transacciones debe anularse para preservar la propiedad de aislamiento de la transacción. Otros eventos transitorios que también pueden provocar la anulación de una transacción incluyen los siguientes:
Problemas de red transitorios
Se aplican cambios en el esquema de la base de datos mientras una transacción está en proceso de confirmación.
La instancia de Spanner no tiene la capacidad para controlar todas las solicitudes que recibe.
En estos casos, el cliente debe reintentar la transacción anulada hasta que se confirme correctamente o se agote el tiempo de espera. Para los usuarios de las bibliotecas cliente oficiales de Spanner, cada biblioteca implementó un mecanismo de reintento automático. Si usas una versión personalizada del código del cliente, incluye tus confirmaciones de transacciones en un bucle de reintento.
Una transacción de Spanner también se puede anular debido a un error no reintentable, como un tiempo de espera agotado de la transacción, problemas de permisos o un nombre de tabla o columna no válido. No es necesario volver a intentar realizar estas transacciones, y la biblioteca cliente de Spanner devolverá el error de inmediato.
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 |
---|---|---|---|
La transacción se confirmó correctamente en el primer intento. | 1 | 0 | 0 |
Se anuló la transacción debido a un error de tiempo de espera. | 1 | 1 | 0 |
Se anuló la transacción debido a un problema de red transitorio y se confirmó correctamente después de un reintento. | 2 | 1 | 1 |
Se ejecutan 5 transacciones con el mismo FPRINT en un intervalo de 10 minutos. 3 de las transacciones se confirmaron correctamente en el primer intento, mientras que 2 se anularon y, luego, se confirmaron correctamente en el primer reintento. | 7 | 2 | 2 |
Los datos de las tablas de estadísticas de transacciones son datos agregados para un intervalo de tiempo. Para un intervalo en particular, es posible que una transacción se anule y se reintente cerca de los límites, y que se incluya en diferentes buckets. Como resultado, en un intervalo de tiempo determinado, es posible que los reintentos y las anulaciones no sean iguales.
Estas estadísticas están diseñadas para la solución de problemas y la 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 o cualquier otra actividad de mantenimiento, los servidores de Spanner pueden reiniciarse, lo que afecta la precisión de las cifras.
Soluciona problemas de contención de bases de datos con estadísticas de transacciones
Puedes usar código SQL o el panel de Estadísticas de transacciones para ver las transacciones de tu base de datos que podrían causar latencias altas debido a conflictos de bloqueo.
En los siguientes temas, se muestra cómo puedes investigar esas transacciones con código SQL.
Selecciona un período para investigar
Se puede encontrar en la aplicación que usa Spanner.
A los fines de este ejercicio, supongamos que el problema comenzó a ocurrir alrededor de las 5:20 p.m. del 17 de mayo de 2020.
Puedes usar etiquetas de transacción para identificar la fuente de la transacción y correlacionar las tablas de estadísticas de transacciones y de estadísticas de bloqueos para solucionar problemas de contención de bloqueos de manera eficaz. Obtén más información en Solución de problemas con etiquetas de transacción.
Recopila estadísticas de transacciones para el período seleccionado
Para comenzar la investigación, consultaremos la tabla TXN_STATS_TOTAL_10MINUTE
durante el inicio del problema. Los resultados de esta consulta nos mostrarán cómo cambiaron la latencia y otras estadísticas de transacciones durante ese período.
Por ejemplo, la siguiente consulta devuelve las estadísticas de transacciones agregadas desde 4:30 pm
hasta 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;
En la siguiente tabla, se muestran datos de ejemplo de 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 recuento de anulaciones son más altos en los períodos destacados. Podemos elegir cualquier intervalo de 10 minutos en el que la latencia agregada o el recuento de anulaciones sean altos. Elijamos el intervalo que finaliza en 2020-05-17T18:40:00
y usémoslo en el siguiente paso para identificar qué transacciones contribuyen a la latencia alta y al recuento de anulaciones.
Identifica las transacciones que tienen una latencia alta
Ahora consultaremos la tabla TXN_STATS_TOP_10MINUTE
para el intervalo que se seleccionó en el paso anterior. Con estos datos, podemos comenzar a identificar qué transacciones experimentan una latencia o un recuento de anulación atos.
Ejecuta la siguiente consulta para obtener las transacciones que más afectan el rendimiento, ordenadas de forma descendente según la latencia total para nuestro intervalo de ejemplo que finaliza 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 que experimenta una latencia alta debido a una gran cantidad de anulaciones de confirmaciones. También podemos ver una gran cantidad de reintentos de confirmación, lo que indica que los reintentos de confirmación anulados se reintentaron posteriormente. En el siguiente paso, investigaremos más a fondo para ver qué causa este problema.
Identifica las columnas involucradas en una transacción que tiene una latencia alta
En este paso, verificaremos si las transacciones con alta latencia operan en el mismo conjunto de columnas. Para ello, recuperaremos los datos de read_columns
, write_constructive_columns
y write_delete_tables
para las transacciones con un recuento de anulaciones alto. El valor de FPRINT
también será útil en el paso siguiente.
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 promedio más alta leen las mismas columnas. También podemos observar que hay contención de escritura, ya que las transacciones escriben en la misma columna, es decir, TestHigherLatency._exists
.
Determina cómo cambió el rendimiento de las transacciones a lo largo del tiempo
Podemos ver cómo cambiaron las estadísticas asociadas con esta forma de transacción durante un período. Usa la siguiente consulta, en la que $FPRINT es la huella digital de la transacción con latencia alta 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 | latency | 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 | 106,728 | 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 |
En el resultado anterior, podemos observar que la latencia total es alta en el período destacado. Además, siempre que la latencia total sea alta, los valores commit_attempt_count
, commit_abort_count
y commit_retry_count
también serán altos, aunque la latencia de confirmación (commit_latency
) no haya cambiado mucho. Dado que las confirmaciones de transacciones se anulan con más frecuencia, los intentos de confirmación también son altos debido a los reintentos.
Conclusión
En este ejemplo, notamos que el recuento alto de anulaciones de confirmaciones fue la causa de la latencia alta. El siguiente paso es mirar los mensajes de error de anulación de confirmaciones que recibe la aplicación para conocer el motivo de la anulación. Cuando inspeccionamos registros en la aplicación, vemos que la app cambió su carga de trabajo durante este período, es decir, otra forma de transacción se mostró con un valor de attempts_per_second
alto y esa transacción diferente (tal vez un trabajo de limpieza nocturno) fue responsable de los conflictos de bloqueo adicionales.
Identifica las transacciones que no se reintentaron correctamente
En la siguiente consulta, se muestran las transacciones muestreadas en los últimos diez minutos que tienen un recuento alto de anulaciones de confirmación, 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 |
Podemos ver que la transacción con fprint 1557557373282541312 se anuló 44,232 veces, pero nunca se volvió a intentar. Esto parece sospechoso porque el recuento de anulaciones es alto y es poco probable que cada anulación se haya causado por un error no reintentable. Por otro lado, la transacción con la huella digital 5776062322886969344 es menos sospechosa porque el recuento total de anulaciones no es tan alto.
La siguiente consulta devuelve más detalles sobre la transacción con la huella digital 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 para 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 verificar la existencia de 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 cliente personalizada funciona según lo previsto.
¿Qué sigue?
- Obtén más información sobre otras herramientas de introspección.
- Obtén información sobre qué otra información almacena Spanner para cada base de datos en las tablas de esquema de información de la base de datos.
- Obtén más información sobre las prácticas recomendadas de SQL para Spanner.
- Obtén más información para investigar el uso alto de CPU.