Spanner menyediakan tabel bawaan yang menyimpan statistik tentang transaksi. Anda dapat mengambil statistik dari tabel SPANNER_SYS.TXN_STATS*
ini menggunakan pernyataan SQL.
Kapan harus menggunakan statistik transaksi
Statistik transaksi berguna saat menyelidiki masalah performa. Misalnya, Anda dapat memeriksa apakah ada transaksi yang berjalan lambat yang dapat memengaruhi performa atau Kueri Per Detik (QPS) di database. Skenario lainnya adalah saat aplikasi klien Anda mengalami latensi eksekusi transaksi yang tinggi. Menganalisis statistik transaksi dapat membantu menemukan potensi bottleneck, seperti volume update yang besar pada kolom tertentu, yang mungkin memengaruhi latensi.
Ketersediaan
Data SPANNER_SYS
hanya tersedia melalui antarmuka SQL; misalnya:
Halaman Spanner Studio database di Konsol Google Cloud
Perintah
gcloud spanner databases execute-sql
Dasbor Transaction Insights
executeQuery
API
Metode pembacaan tunggal lainnya yang disediakan Spanner tidak mendukung
SPANNER_SYS
.
Statistik latensi yang dikelompokkan berdasarkan transaksi
Tabel berikut melacak statistik untuk transaksi yang memakai resource TOP
selama jangka waktu tertentu.
SPANNER_SYS.TXN_STATS_TOP_MINUTE
: Statistik transaksi digabungkan dari interval 1 menit.SPANNER_SYS.TXN_STATS_TOP_10MINUTE
: Statistik transaksi digabungkan dalam interval 10 menit.SPANNER_SYS.TXN_STATS_TOP_HOUR
: Statistik transaksi digabungkan pada interval 1 jam.
Tabel ini memiliki properti berikut:
Setiap tabel berisi data untuk interval waktu yang tidak tumpang-tindih dari panjang yang ditentukan oleh nama tabel.
Interval didasarkan pada waktu jam. Interval 1 menit berakhir pada menit, interval 10 menit berakhir setiap 10 menit dimulai pada jam, dan interval 1 jam berakhir pada jam.
Misalnya, pada pukul 11.59.30, interval terbaru yang tersedia untuk kueri SQL adalah:
- 1 menit: 11.58.00–11.58.59
- 10 menit: 11.40–11.49.59
- 1 jam: 10.00–10.59.59
Spanner mengelompokkan statistik berdasarkan FPRINT (Sidik jari) transaksi. Jika ada tag transaksi, FPRINT adalah hash tag tersebut. Jika tidak, hash akan dihitung berdasarkan operasi yang terlibat dalam transaksi.
Karena statistik dikelompokkan berdasarkan FPRINT, jika transaksi yang sama dijalankan beberapa kali dalam interval waktu apa pun, kita masih hanya melihat satu entri untuk transaksi tersebut dalam tabel ini.
Setiap baris berisi statistik untuk semua eksekusi transaksi tertentu yang statistiknya dicatat oleh Spanner selama interval yang ditentukan.
Jika Spanner tidak dapat menyimpan statistik untuk semua transaksi yang dijalankan selama interval di tabel ini, sistem akan memprioritaskan transaksi dengan latensi tertinggi, percobaan commit, dan byte yang ditulis selama interval yang ditentukan.
Skema tabel
Nama kolom | Jenis | Deskripsi |
---|---|---|
INTERVAL_END |
TIMESTAMP |
Akhir interval waktu saat eksekusi transaksi yang disertakan terjadi. |
TRANSACTION_TAG |
STRING |
Tag transaksi opsional untuk operasi transaksi ini. Untuk mengetahui informasi selengkapnya tentang penggunaan tag, lihat Memecahkan masalah dengan tag transaksi. Statistik untuk beberapa transaksi yang memiliki string tag yang sama dikelompokkan dalam satu baris dengan `Transition_TAG` yang cocok dengan string tag tersebut. |
FPRINT |
INT64 |
Hash TRANSACTION_TAG jika ada; Jika tidak, hash akan dihitung berdasarkan operasi yang terlibat dalam transaksi.
INTERVAL_END dan FPRINT bersama-sama berfungsi sebagai
kunci unik untuk tabel ini. |
READ_COLUMNS |
ARRAY<STRING> |
Kumpulan kolom yang telah dibaca oleh transaksi. |
WRITE_CONSTRUCTIVE_COLUMNS |
ARRAY<STRING> |
Kumpulan kolom yang ditulis secara konstruktif (yang ditetapkan ke nilai baru) oleh transaksi.
Untuk aliran perubahan, jika transaksi yang melibatkan penulisan ke kolom dan tabel yang dipantau oleh aliran perubahan, WRITE_CONSTRUCTIVE_COLUMNS akan berisi dua kolom - .data dan ._exists
1, yang diawali dengan nama aliran perubahan.
|
WRITE_DELETE_TABLES |
ARRAY<STRING> |
Kumpulan tabel yang barisnya telah dihapus atau diganti dengan transaksi. |
ATTEMPT_COUNT |
INT64 |
Total berapa kali transaksi dicoba, termasuk upaya yang membatalkan sebelum memanggil `commit`. |
COMMIT_ATTEMPT_COUNT |
INT64 |
Jumlah total upaya commit transaksi. Ini harus cocok dengan jumlah panggilan ke metode commit transaksi.
|
COMMIT_ABORT_COUNT |
INT64 |
Jumlah total upaya transaksi yang dibatalkan, termasuk yang dibatalkan sebelum memanggil metode commit transaksi.
|
COMMIT_RETRY_COUNT |
INT64 |
Total jumlah percobaan ulang yang merupakan percobaan ulang dari percobaan yang sebelumnya dibatalkan. Transaksi Spanner mungkin dicoba beberapa kali sebelum di-commit karena pertentangan kunci atau peristiwa sementara. Jumlah percobaan ulang yang tinggi dibandingkan dengan percobaan commit menunjukkan bahwa mungkin ada masalah yang perlu diselidiki. Untuk informasi selengkapnya, lihat Memahami transaksi dan jumlah commit di halaman ini. |
COMMIT_FAILED_PRECONDITION_COUNT |
INT64 |
Jumlah total upaya commit transaksi yang menampilkan error prakondisi yang gagal, seperti pelanggaran indeks UNIQUE , baris sudah ada, baris tidak ditemukan, dan seterusnya.
|
AVG_PARTICIPANTS |
FLOAT64 |
Jumlah rata-rata peserta dalam setiap upaya commit. Untuk mempelajari peserta lebih lanjut, lihat Aktivitas Bacaan & Penulisan Spanner. |
AVG_TOTAL_LATENCY_SECONDS |
FLOAT64 |
Detik rata-rata yang diambil dari operasi pertama transaksi untuk di-commit/dibatalkan. |
AVG_COMMIT_LATENCY_SECONDS |
FLOAT64 |
Jumlah detik rata-rata yang diperlukan untuk menjalankan operasi commit. |
AVG_BYTES |
FLOAT64 |
Jumlah rata-rata byte yang ditulis oleh transaksi. |
TOTAL_LATENCY_DISTRIBUTION |
ARRAY<STRUCT>
|
Histogram total latensi commit, yang merupakan waktu dari waktu mulai operasi transaksional pertama hingga waktu commit atau pembatalan, untuk semua percobaan transaksi.
Jika transaksi dibatalkan beberapa kali dan kemudian berhasil di-commit, latensi akan diukur untuk setiap percobaan hingga commit akhir berhasil. Nilai tersebut diukur dalam detik.
Array berisi satu elemen dan memiliki jenis berikut:
Untuk menghitung latensi persentil yang diinginkan dari distribusi, gunakan fungsi Untuk informasi selengkapnya, lihat Persentil dan metrik nilai distribusi. |
OPERATIONS_BY_TABLE |
ARRAY<STRUCT> |
Dampak operasi
Kolom ini membantu memvisualisasikan beban pada tabel dan memberikan insight tentang kecepatan operasi penulisan ke tabel.
Tentukan array sebagai berikut:
|
1 _exists
adalah kolom internal yang digunakan untuk memeriksa apakah ada
baris tertentu atau tidak.
Contoh kueri
Bagian ini mencakup beberapa contoh pernyataan SQL yang mengambil statistik transaksi. Anda dapat menjalankan pernyataan SQL ini menggunakan library klien, gcloud spanner, atau Konsol Google Cloud.
Cantumkan statistik dasar untuk setiap transaksi dalam jangka waktu tertentu
Kueri berikut menampilkan data mentah untuk transaksi teratas pada menit sebelumnya.
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 kueri
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 |
Mencantumkan transaksi dengan latensi commit rata-rata tertinggi
Kueri berikut menampilkan transaksi dengan latensi commit rata-rata yang tinggi pada jam sebelumnya, yang diurutkan dari latensi commit rata-rata tertinggi ke terendah.
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 kueri
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 |
Menemukan latensi rata-rata transaksi yang membaca kolom tertentu
Kueri berikut menampilkan informasi latensi rata-rata untuk transaksi yang membaca kolom ADDRESS dari statistik 1 jam:
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 kueri
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 |
Mencantumkan transaksi berdasarkan jumlah rata-rata byte yang diubah
Kueri berikut menampilkan transaksi yang diambil sampelnya dalam satu jam terakhir, yang diurutkan berdasarkan jumlah rata-rata byte yang diubah oleh transaksi.
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 kueri
fprint | read_columns | write_constructive_columns | write_delete_tables | avg_bytes |
---|---|---|---|---|
40015598317 |
[] |
[] |
["Users"] |
25286 |
77848338483 |
[] |
[] |
["Cars", "Routes"] |
12005 |
20524969030 |
["ID", "ADDRESS"] |
[] |
["Users"] |
10923 |
Statistik agregat
SPANNER_SYS
juga berisi tabel untuk menyimpan data gabungan untuk semua transaksi yang statistiknya direkam oleh Spanner dalam jangka waktu tertentu:
SPANNER_SYS.TXN_STATS_TOTAL_MINUTE
: Statistik gabungan untuk semua transaksi selama interval 1 menitSPANNER_SYS.TXN_STATS_TOTAL_10MINUTE
: Statistik gabungan untuk semua transaksi selama interval 10 menitSPANNER_SYS.TXN_STATS_TOTAL_HOUR
: Statistik gabungan untuk semua transaksi selama interval 1 jam
Tabel statistik gabungan memiliki properti berikut:
Setiap tabel berisi data untuk interval waktu yang tidak tumpang-tindih dari panjang yang ditentukan oleh nama tabel.
Interval didasarkan pada waktu jam. Interval 1 menit berakhir pada menit, interval 10 menit berakhir setiap 10 menit dimulai pada jam, dan interval 1 jam berakhir pada jam.
Misalnya, pada pukul 11.59.30, interval terbaru yang tersedia untuk kueri SQL pada statistik transaksi gabungan adalah:
- 1 menit: 11.58.00–11.58.59
- 10 menit: 11.40–11.49.59
- 1 jam: 10.00–10.59.59
Setiap baris berisi statistik untuk semua transaksi yang dijalankan melalui database selama interval yang ditentukan, yang digabungkan bersama. Hanya ada satu baris per interval waktu.
Statistik yang dicatat dalam tabel
SPANNER_SYS.TXN_STATS_TOTAL_*
mungkin menyertakan transaksi yang tidak dicatat oleh Spanner dalam tabelSPANNER_SYS.TXN_STATS_TOP_*
.Beberapa kolom dalam tabel ini ditampilkan sebagai metrik di Cloud Monitoring. Metrik yang diekspos adalah:
- Jumlah percobaan commit
- Melakukan commit jumlah percobaan ulang
- Peserta transaksi
- Latensi transaksi
- Byte yang ditulis
Untuk informasi selengkapnya, lihat Metrik Spanner.
Skema tabel
Nama kolom | Jenis | Deskripsi |
---|---|---|
INTERVAL_END |
TIMESTAMP |
Akhir interval waktu saat statistik ini ditangkap. |
ATTEMPT_COUNT |
INT64 |
Total berapa kali transaksi dicoba, termasuk upaya yang dibatalkan sebelum memanggil `commit`. |
COMMIT_ATTEMPT_COUNT |
INT64 |
Jumlah total upaya commit transaksi. Ini harus cocok dengan jumlah panggilan ke metode commit transaksi.
|
COMMIT_ABORT_COUNT |
INT64 |
Jumlah total upaya transaksi yang dibatalkan, termasuk yang dibatalkan sebelum memanggil metode commit transaksi. |
COMMIT_RETRY_COUNT |
INT64 |
Jumlah upaya commit yang merupakan percobaan ulang dari upaya yang sebelumnya dibatalkan. Transaksi Spanner mungkin telah dicoba beberapa kali sebelum di-commit karena pertentangan kunci atau peristiwa sementara. Jumlah percobaan ulang yang tinggi dibandingkan dengan percobaan commit menunjukkan bahwa mungkin ada masalah yang perlu diselidiki. Untuk informasi selengkapnya, lihat Memahami transaksi dan jumlah commit di halaman ini. |
COMMIT_FAILED_PRECONDITION_COUNT |
INT64 |
Jumlah total upaya commit transaksi yang menampilkan error prakondisi yang gagal, seperti pelanggaran indeks UNIQUE , baris sudah ada, baris tidak ditemukan, dan seterusnya.
|
AVG_PARTICIPANTS |
FLOAT64 |
Jumlah rata-rata peserta dalam setiap upaya commit. Untuk mempelajari peserta lebih lanjut, lihat Aktivitas Bacaan & Penulisan Spanner. |
AVG_TOTAL_LATENCY_SECONDS |
FLOAT64 |
Detik rata-rata yang diambil dari operasi pertama transaksi untuk di-commit/dibatalkan. |
AVG_COMMIT_LATENCY_SECONDS |
FLOAT64 |
Jumlah detik rata-rata yang diperlukan untuk menjalankan operasi commit. |
AVG_BYTES |
FLOAT64 |
Jumlah rata-rata byte yang ditulis oleh transaksi. |
TOTAL_LATENCY_DISTRIBUTION |
ARRAY<STRUCT>
|
Histogram total latensi commit, yang merupakan waktu dari waktu mulai operasi transaksional pertama hingga waktu commit atau pembatalan untuk semua percobaan transaksi.
Jika transaksi dibatalkan beberapa kali dan kemudian berhasil di-commit, latensi akan diukur untuk setiap percobaan hingga commit akhir berhasil. Nilai tersebut diukur dalam detik.
Array berisi satu elemen dan memiliki jenis berikut:
Untuk menghitung latensi persentil yang diinginkan dari distribusi, gunakan fungsi Untuk informasi selengkapnya, lihat Persentil dan metrik nilai distribusi. |
OPERATIONS_BY_TABLE |
ARRAY<STRUCT> |
Dampak operasi
Kolom ini membantu memvisualisasikan beban pada tabel dan memberikan insight tentang kecepatan penulisan transaksi ke tabel.
Tentukan array sebagai berikut:
|
Contoh kueri
Bagian ini mencakup beberapa contoh pernyataan SQL yang mengambil statistik transaksi. Anda dapat menjalankan pernyataan SQL ini menggunakan library klien, gcloud spanner, atau Konsol Google Cloud.
Menemukan jumlah total upaya commit untuk transaksi
Kueri berikut menampilkan jumlah total upaya commit untuk semua transaksi dalam interval 1 menit lengkap terbaru:
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 kueri
interval_end | commit_attempt_count |
---|---|
2020-01-17 11:46:00-08:00 |
21 |
Perhatikan bahwa hanya ada satu baris dalam hasil karena statistik gabungan hanya memiliki
satu entri per interval_end
untuk durasi waktu tertentu.
Menemukan total latensi commit di semua transaksi
Kueri berikut menampilkan total latensi commit di semua transaksi dalam 10 menit sebelumnya:
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 kueri
total_commit_latency_hours |
---|
0.8967 |
Perhatikan bahwa hanya ada satu baris dalam hasil karena statistik gabungan hanya memiliki
satu entri per interval_end
untuk durasi waktu tertentu.
Menemukan latensi persentil ke-99 untuk transaksi
Kueri berikut menampilkan latensi persentil ke-99 untuk transaksi yang berjalan dalam 10 menit sebelumnya:
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 kueri
interval_end | avg_total_latency_seconds | percentile_latency |
---|---|---|
2022-08-17 11:46:00-08:00 |
0.34576998305986395 |
9.00296190476190476 |
Perhatikan perbedaan besar antara latensi persentil rata-rata dan persentil ke-99. Latensi persentil ke-99 membantu mengidentifikasi kemungkinan transaksi pencilan dengan latensi tinggi.
Hanya ada satu baris di hasil karena statistik gabungan hanya memiliki
satu entri per interval_end
untuk durasi waktu tertentu.
Retensi data
Setidaknya, Spanner menyimpan data untuk setiap tabel selama jangka waktu berikut:
SPANNER_SYS.TXN_STATS_TOP_MINUTE
danSPANNER_SYS.TXN_STATS_TOTAL_MINUTE
: Interval yang mencakup 6 jam sebelumnya.SPANNER_SYS.TXN_STATS_TOP_10MINUTE
danSPANNER_SYS.TXN_STATS_TOTAL_10MINUTE
: Interval yang mencakup 4 hari sebelumnya.SPANNER_SYS.TXN_STATS_TOP_HOUR
danSPANNER_SYS.TXN_STATS_TOTAL_HOUR
: Interval yang mencakup 30 hari sebelumnya.
Statistik transaksi di Spanner memberikan insight tentang cara aplikasi menggunakan database, dan berguna saat menyelidiki masalah performa. Misalnya, Anda dapat memeriksa apakah ada transaksi yang berjalan lambat yang mungkin menyebabkan pertentangan, atau Anda dapat mengidentifikasi potensi sumber beban tinggi, seperti volume update yang besar pada kolom tertentu. Dengan mengikuti langkah-langkah berikut, kami akan menunjukkan cara menggunakan statistik transaksi untuk menyelidiki pertentangan dalam database Anda.
Memahami transaksi dan jumlah commit
Transaksi Spanner mungkin harus dicoba beberapa kali sebelum di-commit. Hal ini paling sering terjadi saat dua transaksi mencoba mengerjakan data yang sama secara bersamaan, dan salah satu transaksi harus dibatalkan untuk mempertahankan properti isolasi transaksi. Beberapa peristiwa sementara lainnya yang juga dapat menyebabkan transaksi dibatalkan antara lain:
Masalah jaringan sementara.
Perubahan skema database diterapkan saat transaksi dalam proses commit.
Instance Spanner tidak memiliki kapasitas untuk menangani semua permintaan yang diterimanya.
Dalam skenario tersebut, klien harus mencoba lagi transaksi yang dibatalkan sampai berhasil di-commit atau habis waktunya. Untuk pengguna library klien Spanner resmi, setiap library telah mengimplementasikan mekanisme percobaan ulang otomatis. Jika Anda menggunakan kode klien versi kustom, gabungkan commit transaksi Anda dalam loop percobaan ulang.
Transaksi Spanner juga dapat dibatalkan karena terjadi error yang tidak dapat dicoba ulang, seperti waktu tunggu transaksi habis, masalah izin, atau nama tabel/kolom yang tidak valid. Anda tidak perlu mencoba kembali transaksi semacam itu dan library klien Spanner akan langsung menampilkan error.
Tabel berikut menjelaskan beberapa contoh cara COMMIT_ATTEMPT_COUNT
, COMMIT_ABORT_COUNT
, dan COMMIT_RETRY_COUNT
dicatat ke dalam log dalam berbagai skenario.
Skenario | COMMIT_ATTEMPT_COUNT | COMMIT_ABORT_COUNT | COMMIT_RETRY_COUNT |
---|---|---|---|
Transaksi berhasil di-commit pada upaya pertama. | 1 | 0 | 0 |
Transaksi dibatalkan karena error waktu tunggu. | 1 | 1 | 0 |
Transaksi dibatalkan karena ada masalah jaringan sementara dan berhasil dilakukan setelah satu kali percobaan ulang. | 2 | 1 | 1 |
5 transaksi dengan FPRINT yang sama dijalankan dalam interval 10 menit. 3 transaksi berhasil dilakukan pada upaya pertama, sedangkan 2 transaksi dibatalkan, lalu berhasil dilakukan pada percobaan ulang pertama. | 7 | 2 | 2 |
Data dalam tabel statistik transaksi adalah data gabungan selama interval waktu. Untuk interval tertentu, ada kemungkinan bahwa pembatalan dan percobaan ulang transaksi terjadi di sekitar batas dan termasuk dalam bucket yang berbeda. Akibatnya, pembatalan dan percobaan ulang dalam interval waktu tertentu mungkin tidak sama.
Statistik ini dirancang untuk pemecahan masalah dan introspeksi serta tidak dijamin 100% akurat. Statistik digabungkan dalam memori sebelum disimpan di tabel Spanner. Selama upgrade atau aktivitas pemeliharaan lainnya, server Spanner dapat dimulai ulang, sehingga memengaruhi akurasi angka.
Memecahkan masalah pertentangan database menggunakan statistik transaksi
Anda dapat menggunakan kode SQL atau dasbor Transaction insights untuk melihat transaksi di database Anda yang mungkin menyebabkan latensi tinggi karena pertentangan kunci.
Topik-topik berikut menunjukkan cara menyelidiki transaksi semacam itu dengan menggunakan kode SQL.
Pilih jangka waktu untuk diselidiki
Ini dapat ditemukan dari aplikasi yang menggunakan Spanner.
Untuk tujuan latihan ini, anggaplah masalah mulai terjadi sekitar pukul 17.20 pada 17 Mei 2020.
Anda dapat menggunakan Tag Transaksi untuk mengidentifikasi sumber transaksi dan menghubungkan antara Tabel Statistik Transaksi dan tabel Statistik Kunci untuk pemecahan masalah pertentangan kunci yang efektif. Baca selengkapnya di Pemecahan masalah dengan tag transaksi.
Mengumpulkan statistik transaksi untuk jangka waktu yang dipilih
Untuk memulai penyelidikan, kita akan membuat kueri tabel TXN_STATS_TOTAL_10MINUTE
di sekitar awal masalah. Hasil kueri ini akan menunjukkan perubahan statistik
latensi dan transaksi lainnya selama periode waktu tersebut.
Misalnya, kueri berikut menampilkan statistik transaksi gabungan dari 4:30 pm
ke 7:40 pm
(inklusif).
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;
Tabel berikut mencantumkan contoh data yang ditampilkan dari kueri.
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 | 390.343 | 52.549 |
17-05-2020 17.30.00-07.00 | 0,1314 | 456455 | 76.392 |
17-05-2020 17.40.00-07.00 | 0,1598 | 507774 | 121458 |
17-05-2020 17.50.00-07.00 | 0,1641 | 516587 | 115875 |
17-05-2020 18.00.00-07.00 | 0,1578 | 552711 | 122626 |
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 | 601.994 | 143.044 |
17-05-2020 18.40.00-07.00 | 0,2025 | 604211 | 170.019 |
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 | 112247 |
17-05-2020 19.20.00-07.00 | 0,1367 | 570864 | 100596 |
17-05-2020 19.30:00-07.00 | 0,0894 | 539729 | 65316 |
17-05-2020 19:40:00-07:00 | 0,0820 | 479151 | 40398 |
Di sini kita melihat bahwa latensi gabungan dan jumlah pembatalan lebih tinggi pada periode
yang ditandai. Kita dapat memilih interval 10 menit dengan latensi gabungan dan/atau jumlah pembatalan yang tinggi. Mari kita pilih interval yang berakhir pada 2020-05-17T18:40:00
dan gunakan pada langkah berikutnya untuk mengidentifikasi transaksi mana yang berkontribusi pada latensi tinggi dan jumlah pembatalan.
Mengidentifikasi transaksi yang mengalami latensi tinggi
Sekarang, mari kita buat kueri tabel TXN_STATS_TOP_10MINUTE
untuk interval yang
dipilih pada langkah sebelumnya. Dengan menggunakan data ini, kita dapat mulai mengidentifikasi transaksi mana yang mengalami latensi tinggi dan/atau jumlah pembatalan yang tinggi.
Jalankan kueri berikut untuk mendapatkan transaksi yang paling memengaruhi performa dalam urutan menurun dari total latensi untuk contoh interval yang berakhir pada 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 | 142205 | 129884 |
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 |
Kita dapat melihat dengan jelas bahwa baris pertama (disorot) dalam tabel sebelumnya menunjukkan transaksi yang mengalami latensi tinggi karena tingginya jumlah pembatalan commit. Kita juga dapat melihat tingginya jumlah percobaan ulang commit yang menunjukkan bahwa commit yang dibatalkan kemudian dicoba lagi. Pada langkah berikutnya, kita akan menyelidiki lebih lanjut untuk melihat apa yang menyebabkan masalah ini.
Mengidentifikasi kolom yang terlibat dalam transaksi yang mengalami latensi tinggi
Pada langkah ini, kita akan memeriksa apakah transaksi latensi tinggi beroperasi di
kumpulan kolom yang sama dengan mengambil data read_columns
, write_constructive_columns
, dan
write_delete_tables
untuk transaksi dengan jumlah pembatalan yang tinggi. Nilai FPRINT
juga akan berguna di langkah berikutnya.
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] |
[] |
Seperti yang ditunjukkan output dalam tabel sebelumnya, transaksi dengan rata-rata total latensi
tertinggi membaca kolom yang sama. Kita juga dapat mengamati beberapa pertentangan penulisan karena transaksi ditulis ke kolom yang sama, yaitu TestHigherLatency._exists
.
Menentukan perubahan performa transaksi dari waktu ke waktu
Kita dapat melihat bagaimana statistik yang terkait dengan bentuk transaksi ini telah berubah selama periode waktu tertentu. Gunakan kueri berikut, dengan $FPRINT adalah sidik jari dari transaksi latensi tinggi dari langkah sebelumnya.
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 |
---|---|---|---|---|---|---|---|
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 |
Pada output di atas, kita dapat mengamati bahwa total latensi tinggi selama periode waktu yang ditandai. Dan, di mana pun latensi total tinggi, commit_attempt_count
commit_abort_count
, dan commit_retry_count
juga tinggi meskipun latensi
commit (commit_latency
) tidak banyak berubah. Karena commit transaksi
lebih sering dibatalkan, upaya commit juga tinggi karena
percobaan ulang commit.
Kesimpulan
Dalam contoh ini, kita melihat bahwa jumlah pembatalan commit yang tinggi adalah penyebab latensi
yang tinggi. Langkah berikutnya adalah melihat pesan error pembatalan commit yang diterima oleh aplikasi untuk mengetahui alasan pembatalan. Dengan memeriksa log di
aplikasi, kami melihat bahwa aplikasi benar-benar mengubah beban kerjanya selama waktu
ini, yaitu beberapa bentuk transaksi lain muncul dengan attempts_per_second
yang tinggi,
dan transaksi yang berbeda tersebut (mungkin tugas pembersihan di malam hari) menyebabkan
konflik kunci tambahan.
Mengidentifikasi transaksi yang tidak dicoba lagi dengan benar
Kueri berikut menampilkan transaksi yang diambil sampelnya dalam sepuluh menit terakhir dengan jumlah pembatalan commit yang tinggi, tetapi tidak ada percobaan ulang.
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 |
Kita dapat melihat bahwa transaksi dengan fprint 1557557373282541312 dibatalkan 44.232 kali, tetapi tidak pernah dicoba lagi. Hal ini terlihat mencurigakan karena jumlah pembatalan yang tinggi dan tidak mungkin setiap proses pembatalan disebabkan oleh error yang tidak dapat diulang. Di sisi lain, untuk transaksi dengan fprint 5776062322886969344, transaksi tersebut tidak terlalu mencurigakan karena jumlah total pembatalan tidak terlalu tinggi.
Kueri berikut menampilkan detail selengkapnya tentang transaksi dengan fprint
1557557373282541312 termasuk read_columns
,write_constructive_columns
,
dan write_delete_tables
. Informasi ini membantu mengidentifikasi transaksi dalam
kode klien, tempat logika percobaan ulang dapat ditinjau untuk skenario ini.
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 | ['Penyanyi._exists'] | ['Singers.FirstName', 'Singers.LastName', 'Singers._exists'] | [] | 805228 | 1839 | 0 |
2021-01-27T18:20:00Z | 1557557373282541312 | ['Penyanyi._exists'] | ['Singers.FirstName', 'Singers.LastName', 'Singers._exists'] | [] | 1034429 | 38779 | 0 |
2021-01-27T18:10:00Z | 1557557373282541312 | ['Penyanyi._exists'] | ['Singers.FirstName', 'Singers.LastName', 'Singers._exists'] | [] | 833677 | 2266 | 0 |
2021-01-27T18:00:00Z | 1557557373282541312 | ['Penyanyi._exists'] | ['Singers.FirstName', 'Singers.LastName', 'Singers._exists'] | [] | 694560 | 1348 | 0 |
Kita dapat melihat bahwa transaksi melibatkan pembacaan ke kolom tersembunyi Singers._exists
untuk memeriksa keberadaan baris. Transaksi tersebut juga menulis ke kolom Singers.FirstName
dan Singer.LastName
. Informasi ini dapat membantu
menentukan apakah mekanisme percobaan ulang transaksi yang diterapkan di library klien
kustom Anda berfungsi sebagaimana mestinya.
Langkah selanjutnya
- Pelajari alat Introspeksi lainnya.
- Pelajari informasi lain yang disimpan Spanner untuk setiap database dalam tabel skema informasi database.
- Pelajari praktik terbaik SQL untuk Spanner lebih lanjut.
- Pelajari lebih lanjut cara Menyelidiki penggunaan CPU yang tinggi.