Bila beban kerja database Anda terlalu berat, pertama-tama Anda ingin melihat kueri apa yang sedang berjalan dalam upaya untuk melihat pola kueri. Apakah menulis itu berat? Baca berat? Dimana letak kemacetannya?
Mengidentifikasi Masalah Kueri
Untuk mengetahuinya, Anda dapat mengaktifkan log umum atau log lambat untuk mencoba menangkap kueri yang sedang berjalan dan menulis ke file. Anda juga dapat membaca dari log biner (karena log biner menangkap semua perubahan dalam database) dan melihat pembacaan langsung dari daftar proses yang berjalan di database. Anda bahkan dapat menangkap kueri dari perspektif jaringan dengan melihat melalui tcpdump.
Apa yang harus dilakukan selanjutnya? Anda dapat menganalisis kueri yang ditulis ke file log umum, file log lambat, log biner untuk memeriksa apakah ada sesuatu yang menarik terjadi (mis. kemacetan dalam kueri).
Percona memiliki alat untuk menganalisis kueri jenis ini, bernama pt-query-digest. Ini disertakan ketika Anda menginstal Percona Toolkit, kumpulan alat utilitas yang membantu DBA untuk mengelola database mereka. Di blog ini kita akan melihat alat ini dan bagaimana membandingkannya dengan fitur Manajemen Kueri ClusterControl.
Prosedur Instalasi
Repositori Percona mendukung dua paket Distribusi Linux untuk penyiapan, yaitu distribusi paket berbasis Debian dan berbasis RPM. Instalasinya sederhana seperti yang ditunjukkan di bawah ini :
Paket berbasis Debian (Ubuntu, Debian)
Konfigurasi repositori paket Percona dengan mengunduh paket
wget https://repo.percona.com/apt/percona-release_latest.generic_all.deb
Dan kemudian instal paket yang diunduh menggunakan dpkg
sudo dpkg -i percona-release_latest.generic_all.deb
Setelah itu, jalankan saja instalasi dari package manager
sudo apt-get install percona-toolkit
Paket berbasis RPM (RHEL, CentOS, Oracle Enterprise Linux, Amazon AMI)
Konfigurasikan repositori paket Percona dengan menginstal paket rpm secara langsung.
sudo yum install https://repo.percona.com/yum/percona-release-latest.noarch.rpm
Setelah itu, jalankan saja instalasi dari package manager
sudo apt-get install percona-toolkit
Utilitas Percona akan diinstal di mesin Anda, dan Anda hanya perlu menggunakannya.
Analisis Beban Kerja Kueri
Ada beberapa cara untuk menghasilkan statistik dari beban kerja kueri menggunakan pt-query-digest, di bawah ini adalah perintah bagaimana melakukannya menggunakan file kueri lambat, file umum, menampilkan daftar proses di database, dan membaca log biner.
Hasilkan dari database daftar proses acara
pt-query-digest --processlist h=localhost,D=sbt,u=sbtest,p=12qwaszx --output slowlog > /tmp/slow_query.log
Hasilkan dari file kueri lambat / file kueri umum
pt-query-digest mysql-slow.log > /tmp/slow_query.log
Hasilkan dari log biner. Sebelum Anda menjalankan pt-query-digest, Anda perlu mengekstrak log biner ke dalam format yang dapat dibaca menggunakan mysqlbinlog. Jangan lupa tambahkan opsi --type dan ketik binlog sebagai sumbernya.
pt-query-digest --type binlog mysql-bin.000001.txt > slow_query.log
Setelah selesai membuat file, Anda akan melihat laporan seperti di bawah ini :
# 12s user time, 170ms system time, 27.44M rss, 221.79M vsz
# Current date: Sun May 10 21:40:47 2020
# Hostname: n2
# Files: mysql-1
# Overall: 94.92k total, 47 unique, 2.79k QPS, 27.90x concurrency ________
# Time range: 2020-05-10 21:39:37 to 21:40:11
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 949s 6us 1s 10ms 42ms 42ms 2ms
# Lock time 31s 0 1s 327us 80us 11ms 22us
# Rows sent 69.36k 0 490 0.75 0.99 11.30 0
# Rows examine 196.34k 0 490 2.12 0.99 21.03 0.99
# Rows affecte 55.28k 0 15 0.60 0.99 1.26 0
# Bytes sent 13.12M 11 6.08k 144.93 299.03 219.02 51.63
# Query size 15.11M 5 922 166.86 258.32 83.13 174.84
# Profile
# Rank Query ID Response time Calls R/Call V/M Ite
# ==== ============================= ============== ===== ====== ===== ===
# 1 0xCE367F5CFFCAF46E816F682E... 162.6485 17.1% 199 0.8173 0.03 SELECT order_line? stock?
# 2 0x360F872745C81781F8F75EDE... 107.4898 11.3% 14837 0.0072 0.02 SELECT stock?
# 3 0xE0CE1933D0392DA3A42FAA7C... 102.2281 10.8% 14866 0.0069 0.03 SELECT item?
# 4 0x492B86BCB2B1AE1278147F95... 98.7658 10.4% 14854 0.0066 0.04 INSERT order_line?
# 5 0x9D086C2B787DC3A308043A0F... 93.8240 9.9% 14865 0.0063 0.02 UPDATE stock?
# 6 0x5812BF2C6ED2B9DAACA5D21B... 53.9681 5.7% 1289 0.0419 0.05 UPDATE customer?
# 7 0x51C0DD7AF0A6D908579C28C0... 44.3869 4.7% 864 0.0514 0.03 SELECT customer?
# 8 0xFFFCA4D67EA0A788813031B8... 41.2123 4.3% 3250 0.0127 0.01 COMMIT
# 9 0xFDDEE3813C59881488D9C47F... 36.0707 3.8% 1180 0.0306 0.02 UPDATE customer?
# 10 0x8FBBE0AFA061755CCC1C27AB... 31.6417 3.3% 1305 0.0242 0.03 UPDATE orders?
# 11 0x8AA6EB56551923DB9A49E40A... 23.3281 2.5% 1522 0.0153 0.04 SELECT customer? warehouse?
# 12 0xF34C10B3DA8DB048A630D4C7... 21.1662 2.2% 1305 0.0162 0.03 UPDATE order_line?
# 13 0x59DBA67188951C532AFC2598... 20.8006 2.2% 1503 0.0138 0.33 INSERT new_orders?
# 14 0xDADBEB0FBFA537F5D8722F42... 17.2802 1.8% 1290 0.0134 0.03 SELECT customer?
# 15 0x597A805ADA793440507F3334... 16.4394 1.7% 1516 0.0108 0.03 INSERT orders?
# 16 0x1B1EA568857A6AAC6544B44A... 13.9560 1.5% 1309 0.0107 0.05 SELECT new_orders?
# 17 0xCE3EDD98779478DE17154DCE... 12.1470 1.3% 1322 0.0092 0.05 INSERT history?
# 18 0x9DFD75E88091AA333A777668... 11.6842 1.2% 1311 0.0089 0.05 SELECT orders?
# MISC 0xMISC 39.6393 4.2% 16334 0.0024 0.0 <29 ITEMS>
# Query 1: 6.03 QPS, 4.93x concurrency, ID 0xCE367F5CFFCAF46E816F682E53C0CF03 at byte 30449473
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.03
# Time range: 2020-05-10 21:39:37 to 21:40:10
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 199
# Exec time 17 163s 302ms 1s 817ms 992ms 164ms 816ms
# Lock time 0 9ms 30us 114us 44us 84us 18us 36us
# Rows sent 0 199 1 1 1 1 0 1
# Rows examine 39 76.91k 306 468 395.75 441.81 27.41 381.65
# Rows affecte 0 0 0 0 0 0 0 0
# Bytes sent 0 15.54k 79 80 79.96 76.28 0 76.28
# Query size 0 74.30k 382 384 382.35 381.65 0 381.65
# String:
# Databases sbt
# Hosts localhost
# Last errno 0
# Users sbtest
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms ################################################################
# 1s ####
# 10s+
# Tables
# SHOW TABLE STATUS FROM `sbt` LIKE 'order_line6'\G
# SHOW CREATE TABLE `sbt`.`order_line6`\G
# SHOW TABLE STATUS FROM `sbt` LIKE 'stock6'\G
# SHOW CREATE TABLE `sbt`.`stock6`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT COUNT(DISTINCT (s_i_id))
FROM order_line6, stock6
WHERE ol_w_id = 1
AND ol_d_id = 1
AND ol_o_id < 3050
AND ol_o_id >= 3030
AND s_w_id= 1
AND s_i_id=ol_i_id
AND s_quantity < 18\G
# Query 2: 436.38 QPS, 3.16x concurrency, ID 0x360F872745C81781F8F75EDE9DD44246 at byte 30021546
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.02
# Time range: 2020-05-10 21:39:37 to 21:40:11
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 15 14837
# Exec time 11 107s 44us 233ms 7ms 33ms 13ms 3ms
# Lock time 1 522ms 15us 496us 35us 84us 28us 23us
# Rows sent 20 14.49k 1 1 1 1 0 1
# Rows examine 7 14.49k 1 1 1 1 0 1
# Rows affecte 0 0 0 0 0 0 0 0
# Bytes sent 28 3.74M 252 282 264.46 271.23 8.65 258.32
# Query size 19 3.01M 209 215 213.05 212.52 2.85 212.52
# String:
# Databases sbt
# Hosts localhost
# Last errno 0
# Users sbtest
# Query_time distribution
# 1us
# 10us #
# 100us ##
# 1ms ################################################################
# 10ms #############
# 100ms #
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS FROM `sbt` LIKE 'stock9'\G
# SHOW CREATE TABLE `sbt`.`stock9`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT s_quantity, s_data, s_dist_01 s_dist
FROM stock9
WHERE s_i_id = 60407 AND s_w_id= 2 FOR UPDATE\G
Seperti yang Anda lihat pada hasil laporan pt-query-digest di atas, kami dapat dibagi menjadi 3 bagian.
Ringkasan Laporan
Ada banyak informasi yang dapat Anda temukan di laporan ringkasan, mulai dari server nama host, tanggal Anda menjalankan perintah, informasi terkait kueri yang dicatat, QPS, dan pengambilan kerangka waktu. Selain itu, Anda juga dapat melihat statistik waktu pada setiap Atribut.
# 12s user time, 170ms system time, 27.44M rss, 221.79M vsz
# Current date: Sun May 10 21:40:47 2020
# Hostname: n2
# Files: mysql-1
# Overall: 94.92k total, 47 unique, 2.79k QPS, 27.90x concurrency ________
# Time range: 2020-05-10 21:39:37 to 21:40:11
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 949s 6us 1s 10ms 42ms 42ms 2ms
# Lock time 31s 0 1s 327us 80us 11ms 22us
# Rows sent 69.36k 0 490 0.75 0.99 11.30 0
# Rows examine 196.34k 0 490 2.12 0.99 21.03 0.99
# Rows affecte 55.28k 0 15 0.60 0.99 1.26 0
# Bytes sent 13.12M 11 6.08k 144.93 299.03 219.02 51.63
# Query size 15.11M 5 922 166.86 258.32 83.13 174.84
Pembuatan Profil Kueri Berdasarkan Peringkat
Anda dapat melihat informasi yang berguna dalam kueri pembuatan profil.
# Profile
# Rank Query ID Response time Calls R/Call V/M Ite
# ==== ============================= ============== ===== ====== ===== ===
# 1 0xCE367F5CFFCAF46E816F682E... 162.6485 17.1% 199 0.8173 0.03 SELECT order_line? stock?
# 2 0x360F872745C81781F8F75EDE... 107.4898 11.3% 14837 0.0072 0.02 SELECT stock?
Ada banyak informasi seperti kueri yang berjalan, waktu respons kueri (termasuk penghitungan persentase), berapa banyak panggilan yang dilakukan kueri, dan pembacaan per panggilan.
Distribusi Kueri
Statistik distribusi kueri menjelaskan informasi terperinci berdasarkan peringkat pembuatan profil kueri, Anda dapat melihat konkurensi QPS, informasi statistik yang terkait dengan Atribut kueri.
# Query 1: 6.03 QPS, 4.93x concurrency, ID 0xCE367F5CFFCAF46E816F682E53C0CF03 at byte 30449473
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.03
# Time range: 2020-05-10 21:39:37 to 21:40:10
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 0 199
# Exec time 17 163s 302ms 1s 817ms 992ms 164ms 816ms
# Lock time 0 9ms 30us 114us 44us 84us 18us 36us
# Rows sent 0 199 1 1 1 1 0 1
# Rows examine 39 76.91k 306 468 395.75 441.81 27.41 381.65
# Rows affecte 0 0 0 0 0 0 0 0
# Bytes sent 0 15.54k 79 80 79.96 76.28 0 76.28
# Query size 0 74.30k 382 384 382.35 381.65 0 381.65
# String:
# Databases sbt
# Hosts localhost
# Last errno 0
# Users sbtest
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms ################################################################
# 1s ####
# 10s+
# Tables
# SHOW TABLE STATUS FROM `sbt` LIKE 'order_line6'\G
# SHOW CREATE TABLE `sbt`.`order_line6`\G
# SHOW TABLE STATUS FROM `sbt` LIKE 'stock6'\G
# SHOW CREATE TABLE `sbt`.`stock6`\G
# EXPLAIN /*!50100 PARTITIONS*/
SELECT COUNT(DISTINCT (s_i_id))
FROM order_line6, stock6
WHERE ol_w_id = 1
AND ol_d_id = 1
AND ol_o_id < 3050
AND ol_o_id >= 3030
AND s_w_id= 1
AND s_i_id=ol_i_id
AND s_quantity < 18\G
Ada juga informasi mengenai distribusi waktu query, host, user, dan database.
Pemantauan Kueri dengan ClusterControl
ClusterControl memiliki fitur Pemantauan Kueri yang dapat Anda temukan di tab Monitor Kueri seperti yang ditunjukkan di bawah ini.
Anda dapat melihat informasi terkait kueri yang dijalankan di database, termasuk informasi statistik dan waktu eksekusi. Anda juga dapat mengonfigurasi Pengaturan Monitor Kueri yang masih berada di halaman yang sama. Ada opsi untuk mengaktifkan kueri lambat dan kueri yang tidak menggunakan indeks dengan mengklik Pengaturan
Anda hanya perlu mengatur Waktu Permintaan Panjang, yang merupakan ambang batas kueri yang mengkategorikan lama berdasarkan waktu eksekusi. Juga ada opsi untuk mengaktifkan kueri yang tidak menggunakan indeks.
Kesimpulan
Memantau dan menganalisis beban kerja kueri dapat bermanfaat sehingga Anda mengetahui dan memahami beban kerja database Anda, baik pt-query-digest maupun ClusterControl Query Monitor memberikan informasi terkait kueri yang berjalan di database untuk membantu Anda mencapai pemahaman tersebut.