Gdy obciążenie bazy danych jest nadmiernie obciążone, najpierw chcesz sprawdzić, jakie zapytania są uruchomione, aby zobaczyć wzorzec zapytania. Czy to jest ciężkie? Przeczytaj ciężki? Gdzie jest wąskie gardło?
Identyfikowanie problemów z zapytaniami
Aby to rozgryźć, możesz włączyć dziennik ogólny lub powolny dziennik, aby spróbować przechwycić zapytania, które są uruchomione i zapisują do pliku. Możesz również czytać z dziennika binarnego (ponieważ dziennik binarny przechwytuje wszystkie zmiany w bazie danych) i przeglądać odczyty bezpośrednio z uruchomionej listy procesów w bazie danych. Możesz nawet przechwycić zapytanie z perspektywy sieci, przeglądając tcpdump.
Co dalej? Możesz analizować zapytanie, które jest zapisywane do ogólnego pliku dziennika, wolnego pliku dziennika, dziennika binarnego, aby sprawdzić, czy dzieje się coś ciekawego (np. wąskie gardło w zapytaniu).
Percona ma narzędzie do analizy zapytań tego typu o nazwie pt-query-digest. Jest on dołączany podczas instalacji Percona Toolkit, zestawu narzędzi, które pomagają DBA w zarządzaniu bazami danych. W tym blogu przyjrzymy się temu narzędziu i porównamy je z funkcjami zarządzania zapytaniami w ClusterControl.
Procedura instalacji
Repozytoria Percona obsługują dwa pakiety Linux Distribution do konfiguracji, czyli dystrybucję pakietów opartą na Debianie i RPM. Instalacja jest prosta, jak pokazano poniżej:
Pakiet oparty na Debianie (Ubuntu, Debian)
Skonfiguruj repozytoria pakietów Percona, pobierając pakiet
wget https://repo.percona.com/apt/percona-release_latest.generic_all.deb
A następnie zainstaluj pobrany pakiet za pomocą dpkg
sudo dpkg -i percona-release_latest.generic_all.deb
Po tym wystarczy uruchomić instalację z menedżera pakietów
sudo apt-get install percona-toolkit
Pakiet oparty na RPM (RHEL, CentOS, Oracle Enterprise Linux, Amazon AMI)
Skonfiguruj repozytoria pakietów Percona, instalując pakiet rpm bezpośrednio.
sudo yum install https://repo.percona.com/yum/percona-release-latest.noarch.rpm
Po tym wystarczy uruchomić instalację z menedżera pakietów
sudo apt-get install percona-toolkit
Narzędzia Percona zostaną zainstalowane na twoim komputerze i wystarczy z nich skorzystać.
Analiza obciążenia zapytań
Istnieje kilka sposobów generowania statystyk z obciążenia zapytania za pomocą pt-query-digest, poniżej znajduje się polecenie, jak to zrobić za pomocą powolnego pliku zapytania, pliku ogólnego, pokaż listę procesów w bazie danych i przeczytaj dziennik binarny.
Generuj z bazy danych listy procesów show
pt-query-digest --processlist h=localhost,D=sbt,u=sbtest,p=12qwaszx --output slowlog > /tmp/slow_query.log
Generuj z plików z wolnymi zapytaniami / pliku zapytań ogólnych
pt-query-digest mysql-slow.log > /tmp/slow_query.log
Generuj z dziennika binarnego. Zanim uruchomisz pt-query-digest, musisz wyodrębnić dziennik binarny do czytelnego formatu za pomocą mysqlbinlog. Nie zapomnij dodać opcji --type i wpisać binlog jako źródło.
pt-query-digest --type binlog mysql-bin.000001.txt > slow_query.log
Po zakończeniu generowania pliku zobaczysz raport, jak pokazano poniżej:
# 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
Jak widać na powyższym wyniku raportu pt-query-digest, możemy podzielić na 3 części.
Raport podsumowujący
W raporcie podsumowującym można znaleźć wiele informacji, począwszy od serwera nazw hostów, daty wykonania polecenia, zarejestrowania informacji związanych z zapytaniem, QPS i przechwytywania ram czasowych. Oprócz tego możesz również zobaczyć statystyki czasu dla każdego Atrybutu.
# 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
Profilowanie zapytań na podstawie rangi
Możesz zobaczyć przydatne informacje w zapytaniu profilowania.
# 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?
Istnieje wiele informacji, takich jak uruchomione zapytania, czas odpowiedzi na zapytanie (w tym obliczenia procentowe), ile wywołań wykonuje zapytanie i odczyty na wywołanie.
Dystrybucja zapytań
Statystyki dystrybucji zapytań opisują szczegółowe informacje na podstawie rangi profilowania zapytań, można zobaczyć współbieżność QPS, informacje statystyczne związane z atrybutem zapytania.
# 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
Istnieją również informacje dotyczące dystrybucji czasu zapytań, hosta, użytkownika i bazy danych.
Monitorowanie zapytań za pomocą ClusterControl
ClusterControl posiada funkcję monitorowania zapytań, którą można znaleźć na karcie Monitor zapytań, jak pokazano poniżej.
Możesz zobaczyć informacje związane z zapytaniem, które jest wykonywane w bazie danych, w tym informacje statystyczne i czas realizacji. Możesz także skonfigurować ustawienie monitora zapytań, które nadal znajduje się na tej samej stronie. Istnieje możliwość włączenia powolnych zapytań i zapytań niewykorzystujących indeksu, klikając Ustawienia
Wystarczy ustawić długi czas zapytania, który jest progiem zapytanie, które kategoryzuje przez długi czas na podstawie czasu wykonania. Istnieje również opcja włączenia zapytania, które nie używa indeksów.
Wnioski
Monitorowanie i analizowanie obciążenia zapytań może być korzystne, więc znasz i rozumiesz obciążenie bazy danych, zarówno pt-query-digest, jak i ClusterControl Query Monitor dostarczają informacji związanych z zapytaniem uruchomionym w bazie danych, aby pomóc Ci to zrozumieć.