Problémy s výkonem jsou běžné problémy při správě databází MySQL. Někdy jsou tyto problémy ve skutečnosti způsobeny pomalými dotazy. V tomto blogu se budeme zabývat pomalými dotazy a tím, jak je identifikovat.
Kontrola protokolů pomalých dotazů
MySQL má schopnost filtrovat a protokolovat pomalé dotazy. Existují různé způsoby, jak je můžete prozkoumat, ale nejběžnějším a nejefektivnějším způsobem je použití protokolů pomalých dotazů.
Nejprve musíte zjistit, zda jsou povoleny vaše pomalé protokoly dotazů. Chcete-li se s tím vypořádat, můžete přejít na svůj server a zeptat se na následující proměnnou:
MariaDB [(none)]> show global variables like 'slow%log%';
+---------------------+-------------------------------+
| Variable_name | Value |
+---------------------+-------------------------------+
| slow_query_log | ON |
| slow_query_log_file | /var/log/mysql/mysql-slow.log |
+---------------------+-------------------------------+
2 rows in set (0.001 sec)Musíte zajistit, aby proměnná slow_query_log byla nastavena na hodnotu ON, zatímco soubor slow_query_log_file určuje cestu, kam je třeba umístit protokoly pomalých dotazů. Pokud tato proměnná není nastavena, použije DATA_DIR vašeho datového adresáře MySQL.
Proměnné slow_query_log jsou doprovázeny proměnnými long_query_time a min_examined_row_limit, které ovlivňují fungování pomalého protokolování dotazů. V zásadě fungují protokoly pomalých dotazů jako příkazy SQL, jejichž provedení trvá déle než long_query_time sekund a také vyžadují prozkoumání alespoň min_examined_row_limit řádků. Lze jej použít k vyhledání dotazů, jejichž provedení trvá dlouho, a jsou tedy kandidáty na optimalizaci, a poté můžete pomocí externích nástrojů přinést zprávu za vás, o níž bude řeč později.
Výkazy pro správu (ALTER TABLE, ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE a REPAIR TABLE) standardně nespadají do protokolů pomalých dotazů. Chcete-li to provést, musíte povolit proměnnou log_slow_admin_statements.
Seznam procesů dotazování a Monitor stavu InnoDB
V běžné rutině DBA je tento krok nejběžnějším způsobem, jak určit dlouho běžící dotazy nebo aktivní běžící dotazy, které způsobují snížení výkonu. Mohlo by to dokonce způsobit, že se váš server zasekl a následovaly hromadící se fronty, které se pomalu zvyšují kvůli zámku pokrytému běžícím dotazem. Můžete prostě běžet,
SHOW [FULL] PROCESSLIST;nebo
SHOW ENGINE INNODB STATUS \GPokud používáte ClusterControl, můžete jej najít pomocí
nebo pomocí
Analýza dotazů MySQL
Protokoly pomalých dotazů vám zobrazí seznam dotazů, které byly identifikovány jako pomalé, na základě daných hodnot v systémových proměnných, jak bylo uvedeno výše. Definice pomalých dotazů se může v různých případech lišit, protože existují určité případy, kdy je přijatelný i 10sekundový dotaz, a přesto není pomalý. Pokud je však vaše aplikace OLTP, je velmi běžné, že 10sekundový nebo dokonce 5sekundový dotaz představuje problém nebo způsobuje snížení výkonu vaší databáze. Protokol dotazů MySQL vám v tom pomáhá, ale nestačí otevřít soubor protokolu, protože vám neposkytuje přehled o tom, co jsou tyto dotazy, jak fungují a jaká je frekvence jejich výskytu. Proto vám s tím mohou pomoci nástroje třetích stran.
pt-query-digest
Použití Percona Toolkit, což je nejběžnější nástroj DBA, je použití pt-query-digest. pt-query-digest vám poskytuje čistý přehled o konkrétní sestavě pocházející z vašeho protokolu pomalých dotazů. Tato konkrétní sestava například ukazuje čistý pohled na pochopení sestav pomalých dotazů v konkrétním uzlu:
# A software update is available:
# 100ms user time, 100ms system time, 29.12M rss, 242.41M vsz
# Current date: Mon Feb 3 20:26:11 2020
# Hostname: testnode7
# Files: /var/log/mysql/mysql-slow.log
# Overall: 24 total, 14 unique, 0.00 QPS, 0.02x concurrency ______________
# Time range: 2019-12-12T10:01:16 to 2019-12-12T15:31:46
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 345s 1s 98s 14s 30s 19s 7s
# Lock time 1s 0 1s 58ms 24ms 252ms 786us
# Rows sent 5.72M 0 1.91M 244.14k 1.86M 629.44k 0
# Rows examine 15.26M 0 1.91M 651.23k 1.86M 710.58k 961.27k
# Rows affecte 9.54M 0 1.91M 406.90k 961.27k 546.96k 0
# Bytes sent 305.81M 11 124.83M 12.74M 87.73M 33.48M 56.92
# Query size 1.20k 25 244 51.17 59.77 40.60 38.53
# Profile
# Rank Query ID Response time Calls R/Call V/M
# ==== ================================ ============= ===== ======= =====
# 1 0x00C8412332B2795DADF0E55C163... 98.0337 28.4% 1 98.0337 0.00 UPDATE sbtest?
# 2 0xDEF289292EA9B2602DC12F70C7A... 74.1314 21.5% 3 24.7105 6.34 ALTER TABLE sbtest? sbtest3
# 3 0x148D575F62575A20AB9E67E41C3... 37.3039 10.8% 6 6.2173 0.23 INSERT SELECT sbtest? sbtest
# 4 0xD76A930681F1B4CC9F748B4398B... 32.8019 9.5% 3 10.9340 4.24 SELECT sbtest?
# 5 0x7B9A47FF6967FD905289042DD3B... 20.6685 6.0% 1 20.6685 0.00 ALTER TABLE sbtest? sbtest3
# 6 0xD1834E96EEFF8AC871D51192D8F... 19.0787 5.5% 1 19.0787 0.00 CREATE
# 7 0x2112E77F825903ED18028C7EA76... 18.7133 5.4% 1 18.7133 0.00 ALTER TABLE sbtest? sbtest3
# 8 0xC37F2569578627487D948026820... 15.0177 4.3% 2 7.5088 0.00 INSERT SELECT sbtest? sbtest
# 9 0xDE43B2066A66AFA881D6D45C188... 13.7180 4.0% 1 13.7180 0.00 ALTER TABLE sbtest? sbtest3
# MISC 0xMISC 15.8605 4.6% 5 3.1721 0.0 <5 ITEMS>
# Query 1: 0 QPS, 0x concurrency, ID 0x00C8412332B2795DADF0E55C1631626D at byte 5319
# Scores: V/M = 0.00
# Time range: all events occurred at 2019-12-12T13:23:15
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 4 1
# Exec time 28 98s 98s 98s 98s 98s 0 98s
# Lock time 1 25ms 25ms 25ms 25ms 25ms 0 25ms
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 12 1.91M 1.91M 1.91M 1.91M 1.91M 0 1.91M
# Rows affecte 20 1.91M 1.91M 1.91M 1.91M 1.91M 0 1.91M
# Bytes sent 0 67 67 67 67 67 0 67
# Query size 7 89 89 89 89 89 0 89
# String:
# Databases test
# Hosts localhost
# Last errno 0
# Users root
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s
# 10s+ ################################################################
# Tables
# SHOW TABLE STATUS FROM `test` LIKE 'sbtest3'\G
# SHOW CREATE TABLE `test`.`sbtest3`\G
update sbtest3 set c=substring(MD5(RAND()), -16), pad=substring(MD5(RAND()), -16) where 1\G
# Converted for EXPLAIN
# EXPLAIN /*!50100 PARTITIONS*/
select c=substring(MD5(RAND()), -16), pad=substring(MD5(RAND()), -16) from sbtest3 where 1\G
# Query 2: 0.00 QPS, 0.01x concurrency, ID 0xDEF289292EA9B2602DC12F70C7A041A9 at byte 3775
# Scores: V/M = 6.34
# Time range: 2019-12-12T12:41:47 to 2019-12-12T15:25:14
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 12 3
# Exec time 21 74s 6s 36s 25s 35s 13s 30s
# Lock time 0 13ms 1ms 8ms 4ms 8ms 3ms 3ms
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 0 0 0 0 0 0 0
# Rows affecte 0 0 0 0 0 0 0 0
# Bytes sent 0 144 44 50 48 49.17 3 49.17
# Query size 8 99 33 33 33 33 0 33
# String:
# Databases test
# Hosts localhost
# Last errno 0 (2/66%), 1317 (1/33%)
# Users root
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s ################################
# 10s+ ################################################################
# Tables
# SHOW TABLE STATUS FROM `test` LIKE 'sbtest3'\G
# SHOW CREATE TABLE `test`.`sbtest3`\G
ALTER TABLE sbtest3 ENGINE=INNODB\GPoužití performance_schema
Pomalé protokoly dotazů mohou být problémem, pokud nemáte přímý přístup k souboru, například pomocí RDS nebo plně spravovaných databázových služeb, jako je Google Cloud SQL nebo Azure SQL. I když k aktivaci těchto funkcí může být potřeba několik proměnných, hodí se to při dotazování na dotazy přihlášené do vašeho systému. Můžete si jej objednat pomocí standardního příkazu SQL, abyste získali částečný výsledek. Například,
mysql> SELECT SCHEMA_NAME, DIGEST, DIGEST_TEXT, COUNT_STAR, SUM_TIMER_WAIT/1000000000000 SUM_TIMER_WAIT_SEC, MIN_TIMER_WAIT/1000000000000 MIN_TIMER_WAIT_SEC, AVG_TIMER_WAIT/1000000000000 AVG_TIMER_WAIT_SEC, MAX_TIMER_WAIT/1000000000000 MAX_TIMER_WAIT_SEC, SUM_LOCK_TIME/1000000000000 SUM_LOCK_TIME_SEC, FIRST_SEEN, LAST_SEEN FROM events_statements_summary_by_digest;
+--------------------+----------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+------------+--------------------+--------------------+--------------------+--------------------+-------------------+---------------------+---------------------+
| SCHEMA_NAME | DIGEST | DIGEST_TEXT | COUNT_STAR | SUM_TIMER_WAIT_SEC | MIN_TIMER_WAIT_SEC | AVG_TIMER_WAIT_SEC | MAX_TIMER_WAIT_SEC | SUM_LOCK_TIME_SEC | FIRST_SEEN | LAST_SEEN |
+--------------------+----------------------------------+-----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+------------+--------------------+--------------------+--------------------+--------------------+-------------------+---------------------+---------------------+
| NULL | 390669f3d1f72317dab6deb40322d119 | SELECT @@`skip_networking` , @@`skip_name_resolve` , @@`have_ssl` = ? , @@`ssl_key` , @@`ssl_ca` , @@`ssl_capath` , @@`ssl_cert` , @@`ssl_cipher` , @@`ssl_crl` , @@`ssl_crlpath` , @@`tls_version` | 1 | 0.0373 | 0.0373 | 0.0373 | 0.0373 | 0.0000 | 2020-02-03 20:22:54 | 2020-02-03 20:22:54 |
| NULL | fba95d44e3d0a9802dd534c782314352 | SELECT `UNIX_TIMESTAMP` ( ) | 2 | 0.0002 | 0.0001 | 0.0001 | 0.0001 | 0.0000 | 2020-02-03 20:22:57 | 2020-02-03 20:23:00 |
| NULL | 18c649da485456d6cdf12e4e6b0350e9 | SELECT @@GLOBAL . `SERVER_ID` | 2 | 0.0001 | 0.0001 | 0.0001 | 0.0001 | 0.0000 | 2020-02-03 20:22:57 | 2020-02-03 20:23:00 |
| NULL | dd356b8a5a6ed0d7aee2abd939cdb6c9 | SET @? = ? | 6 | 0.0003 | 0.0000 | 0.0001 | 0.0001 | 0.0000 | 2020-02-03 20:22:57 | 2020-02-03 20:23:00 |
| NULL | 1c5ae643e930af6d069845d74729760d | SET @? = @@GLOBAL . `binlog_checksum` | 2 | 0.0001 | 0.0001 | 0.0001 | 0.0001 | 0.0000 | 2020-02-03 20:22:57 | 2020-02-03 20:23:00 |
| NULL | ad5208ffa004a6ad7e26011b73cbfb4c | SELECT @? | 2 | 0.0001 | 0.0000 | 0.0000 | 0.0001 | 0.0000 | 2020-02-03 20:22:57 | 2020-02-03 20:23:00 |
| NULL | ed0d1eb982c106d4231b816539652907 | SELECT @@GLOBAL . `GTID_MODE` | 2 | 0.0001 | 0.0000 | 0.0000 | 0.0001 | 0.0000 | 2020-02-03 20:22:57 | 2020-02-03 20:23:00 |
| NULL | cb47e22372fdd4441486b02c133fb94f | SELECT @@GLOBAL . `SERVER_UUID` | 2 | 0.0001 | 0.0000 | 0.0000 | 0.0001 | 0.0000 | 2020-02-03 20:22:57 | 2020-02-03 20:23:00 |
| NULL | 73301368c301db5d2e3db5626a21b647 | SELECT @@GLOBAL . `rpl_semi_sync_master_enabled` | 2 | 0.0001 | 0.0000 | 0.0000 | 0.0000 | 0.0000 | 2020-02-03 20:22:57 | 2020-02-03 20:23:00 |
| NULL | 0ff7375c5f076ba5c040e78a9250a659 | SELECT @@`version_comment` LIMIT ? | 1 | 0.0001 | 0.0001 | 0.0001 | 0.0001 | 0.0000 | 2020-02-03 20:45:59 | 2020-02-03 20:45:59 |
| NULL | 5820f411e67a393f987c6be5d81a011d | SHOW TABLES FROM `performance_schema` | 1 | 0.0008 | 0.0008 | 0.0008 | 0.0008 | 0.0002 | 2020-02-03 20:46:11 | 2020-02-03 20:46:11 |
| NULL | a022a0ab966c51eb820da1521349c7ef | SELECT SCHEMA ( ) | 1 | 0.0005 | 0.0005 | 0.0005 | 0.0005 | 0.0000 | 2020-02-03 20:46:29 | 2020-02-03 20:46:29 |
| performance_schema | e4833a7c1365b0b4492e9a514f7b3bd4 | SHOW SCHEMAS | 1 | 0.1167 | 0.1167 | 0.1167 | 0.1167 | 0.0001 | 2020-02-03 20:46:29 | 2020-02-03 20:46:29 |
| performance_schema | 1107f048fe6d970cb6a553bd4727a1b4 | SHOW TABLES | 1 | 0.0002 | 0.0002 | 0.0002 | 0.0002 | 0.0000 | 2020-02-03 20:46:29 | 2020-02-03 20:46:29 |
...Můžete použít tabulku performance_schema.events_statements_summary_by_digest. Přestože existuje šance, že položky v tabulkách z performance_schema budou zarovnané, můžete se rozhodnout uložit to do konkrétní tabulky. Podívejte se na tento externí příspěvek z Percona MySQL query digest s Performance Schema.
V případě, že vás zajímá, proč musíme rozdělit sloupce doby čekání (SUM_TIMER_WAIT, MIN_TIMER_WAIT_SEC, AVG_TIMER_WAIT_SEC), tyto sloupce používají pikosekundy, takže možná budete muset udělat trochu matematiky nebo zaokrouhlit je pro vás čitelnější.
Analýza pomalých dotazů pomocí ClusterControl
Pokud používáte ClusterControl, existují různé způsoby, jak se s tím vypořádat. Například v clusteru MariaDB, který mám níže, se zobrazí následující karta (Monitor dotazů) a její rozevírací položky (Nejlepší dotazy, Spuštěné dotazy, Odlehlé hodnoty dotazů):
- Nejčastější dotazy – souhrnný seznam všech vašich nejčastějších dotazů běžících na všech uzlech vašeho databázového clusteru
- Spuštěné dotazy – Zobrazení aktuálních spuštěných dotazů ve vašem databázovém clusteru podobně jako příkaz SHOW FULL PROCESSLIST v MySQL
- Odlehlé hodnoty dotazu – Zobrazí dotazy, které jsou odlehlé. Odlehlá hodnota je dotaz, který trvá déle než normální dotaz tohoto typu.
Kromě toho ClusterControl také zachycuje výkon dotazů pomocí grafů, které vám poskytují rychlý přehled o výkonu vašeho databázového systému ve vztahu k výkonu dotazů. Viz níže,
Počkejte, ještě není konec. ClusterControl také nabízí metriku s vysokým rozlišením pomocí Prometheus a předvádí velmi podrobné metriky a zachycuje statistiky v reálném čase ze serveru. Diskutovali jsme o tom v našich předchozích blozích, které jsou rozděleny do dvou sérií blogů. Podívejte se na blogy 1 a pak 2. Nabízí vám, jak efektivně monitorovat nejen pomalé dotazy, ale i celkový výkon vašich databázových serverů MySQL, MariaDB nebo Percona.
V ClusterControl jsou také další nástroje, které poskytují ukazatele a rady, které mohou způsobit zpomalení výkonu dotazů, i když k tomu ještě nedošlo nebo je nezachytil protokol pomalých dotazů. Podívejte se na kartu Výkon, jak je vidět níže,
tyto položky vám poskytují následující:
- Přehled – Na této stránce si můžete prohlédnout grafy různých databázových čítačů
- Poradci – seznamy výsledků plánovaných poradců vytvořených v ClusterControl> Správa> Developer Studio pomocí ClusterControl DSL.
- Stav DB – Stav DB poskytuje rychlý přehled o stavu MySQL napříč všemi uzly vaší databáze, podobně jako příkaz SHOW STATUS
- Proměnné DB – Proměnné DB poskytují rychlý přehled proměnných MySQL, které jsou nastaveny ve všech uzlech vaší databáze, podobně jako příkaz SHOW GLOBAL VARIABLES
- DB Růst – Poskytuje shrnutí růstu vaší databáze a tabulek na denní bázi za posledních 30 dní.
- Stav InnoDB – Načte aktuální výstup monitoru InnoDB pro vybraného hostitele, podobně jako příkaz SHOW ENGINE INNODB STATUS.
- Schema Analyzer – analyzuje databázová schémata na chybějící primární klíče, nadbytečné indexy a tabulky pomocí úložiště MyISAM.
- Protokol transakcí – uvádí dlouhotrvající transakce a uváznutí v databázovém clusteru, kde můžete snadno zobrazit, jaké transakce zablokování způsobují. Výchozí práh doby dotazu je 30 sekund.
Závěr
Sledování vašeho problému s výkonem MySQL není s MySQL opravdu obtížné. Existují různé externí nástroje, které vám poskytují efektivitu a možnosti, které hledáte. Nejdůležitější je, že se snadno používá a jste schopni zajistit produktivitu práce. Opravte nevyřešené problémy nebo se dokonce vyhněte určité katastrofě dříve, než k ní dojde.