Problemy z wydajnością są częstymi problemami podczas administrowania bazami danych MySQL. Czasami te problemy są w rzeczywistości spowodowane wolnymi zapytaniami. Na tym blogu zajmiemy się powolnymi zapytaniami i sposobami ich identyfikacji.
Sprawdzanie dzienników powolnych zapytań
MySQL ma możliwość filtrowania i rejestrowania wolnych zapytań. Można je zbadać na różne sposoby, ale najczęstszym i najskuteczniejszym sposobem jest użycie wolnych dzienników zapytań.
Musisz najpierw określić, czy logi wolnych zapytań są włączone. Aby sobie z tym poradzić, możesz przejść do swojego serwera i zapytać o następującą zmienną:
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)
Musisz upewnić się, że zmienna slow_query_log jest ustawiona na ON, podczas gdy plik slow_query_log_file określa ścieżkę, w której musisz umieścić dzienniki powolnych zapytań. Jeśli ta zmienna nie jest ustawiona, użyje DATA_DIR twojego katalogu danych MySQL.
Zmienne slow_query_log, którym towarzyszy zmienna long_query_time i min_examined_row_limit, mają wpływ na działanie rejestrowania powolnych zapytań. Zasadniczo powolne dzienniki zapytań działają jako instrukcje SQL, których wykonanie trwa dłużej niż long_query_time sekund, a także wymagają sprawdzenia co najmniej wierszy min_examined_row_limit. Można go użyć do znalezienia zapytań, których wykonanie zajmuje dużo czasu i dlatego są kandydatami do optymalizacji, a następnie możesz użyć zewnętrznych narzędzi, aby dostarczyć raport, który zostanie omówiony później.
Domyślnie instrukcje administracyjne (ALTER TABLE, ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE i REPAIR TABLE) nie trafiają do dzienników powolnych zapytań. W tym celu musisz włączyć zmienną log_slow_admin_statements.
Zapytywanie o listę procesów i Monitor stanu InnoDB
W normalnej procedurze DBA ten krok jest najczęstszym sposobem określenia długo działających lub aktywnych zapytań, które powodują pogorszenie wydajności. Może to nawet spowodować zablokowanie serwera, a następnie nagromadzenie kolejek, które powoli rosną z powodu blokady objętej uruchomionym zapytaniem. Możesz po prostu biegać,
SHOW [FULL] PROCESSLIST;
lub
SHOW ENGINE INNODB STATUS \G
Jeśli używasz ClusterControl, możesz go znaleźć, używając
lub
Analiza zapytań MySQL
Dzienniki powolnych zapytań pokażą listę zapytań, które zostały zidentyfikowane jako powolne na podstawie podanych wartości w zmiennych systemowych, jak wspomniano wcześniej. Definicja powolnych zapytań może się różnić w różnych przypadkach, ponieważ istnieją pewne sytuacje, w których nawet 10-sekundowe zapytanie jest dopuszczalne i nadal nie jest wolne. Jeśli jednak aplikacja jest OLTP, bardzo często 10-sekundowe lub nawet 5-sekundowe zapytanie stanowi problem lub powoduje pogorszenie wydajności bazy danych. Dziennik zapytań MySQL pomaga w tym, ale nie wystarczy otworzyć plik dziennika, ponieważ nie zapewnia przeglądu, czym są te zapytania, jak działają i jaka jest częstotliwość ich występowania. Dlatego narzędzia innych firm mogą Ci w tym pomóc.
pt-zapytanie-przegląd
Korzystanie z Percona Toolkit, który mogę powiedzieć, że jest to najpowszechniejsze narzędzie DBA, polega na użyciu pt-query-digest. pt-query-digest zapewnia przejrzysty przegląd konkretnego raportu pochodzącego z twojego wolnego dziennika zapytań. Na przykład ten konkretny raport pokazuje czystą perspektywę zrozumienia raportów powolnych zapytań w określonym węźle:
# 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\G
Korzystanie z performance_schema
Dzienniki powolnych zapytań mogą stanowić problem, jeśli nie masz bezpośredniego dostępu do pliku, takiego jak korzystanie z usług RDS lub w pełni zarządzanych usług baz danych, takich jak Google Cloud SQL lub Azure SQL. Chociaż do włączenia tych funkcji może być potrzebne kilka zmiennych, jest to przydatne podczas wykonywania zapytań dotyczących zapytań zalogowanych w systemie. Możesz go zamówić za pomocą standardowej instrukcji SQL w celu pobrania częściowego wyniku. Na przykład
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 |
...
Możesz użyć tabeli performance_schema.events_statements_summary_by_digest. Chociaż są szanse, że wpisy w tabelach z performance_schema zostaną opróżnione, możesz zdecydować się zapisać to w konkretnej tabeli. Spójrz na ten zewnętrzny post z podsumowania zapytań Percona MySQL ze schematem wydajności.
Jeśli zastanawiasz się, dlaczego musimy podzielić kolumny czasu oczekiwania (SUM_TIMER_WAIT, MIN_TIMER_WAIT_SEC, AVG_TIMER_WAIT_SEC), te kolumny wykorzystują pikosekundy, więc może być konieczne wykonanie obliczeń matematycznych lub jest dla ciebie bardziej czytelny.
Analiza powolnych zapytań za pomocą ClusterControl
Jeśli używasz ClusterControl, istnieją różne sposoby radzenia sobie z tym. Na przykład w klastrze MariaDB, który mam poniżej, pokazuje następującą kartę (Monitor zapytań) i jej pozycje rozwijane (Najpopularniejsze zapytania, Uruchomione zapytania, Elementy odstające zapytań):
- Najczęstsze zapytania – zagregowana lista wszystkich Twoich najczęstszych zapytań uruchomionych we wszystkich węzłach klastra bazy danych
- Uruchomione zapytania - Zobacz bieżące zapytania uruchomione w klastrze bazy danych, podobnie jak polecenie SHOW FULL PROCESSLIST w MySQL
- Wyjątkowe wartości zapytań — wyświetla zapytania, które są wartościami odstającymi. Wartość odstająca to zapytanie, które zajmuje więcej czasu niż zwykłe zapytanie tego typu.
Co więcej, ClusterControl przechwytuje również wydajność zapytań za pomocą wykresów, które zapewniają szybki wgląd w wydajność systemu bazy danych w odniesieniu do wydajności zapytań. Zobacz poniżej,
Czekaj, to jeszcze nie koniec. ClusterControl oferuje również metrykę o wysokiej rozdzielczości przy użyciu Prometheusa i prezentuje bardzo szczegółowe metryki oraz przechwytuje statystyki w czasie rzeczywistym z serwera. Omówiliśmy to w naszych poprzednich blogach, które są podzielone na dwie części. Sprawdź część 1, a następnie część 2 blogi. Oferuje sposoby skutecznego monitorowania nie tylko powolnych zapytań, ale także ogólnej wydajności serwerów baz danych MySQL, MariaDB lub Percona.
Istnieją również inne narzędzia w ClusterControl, które dostarczają wskaźników i podpowiedzi, które mogą spowodować spowolnienie wydajności zapytań, nawet jeśli jeszcze nie wystąpiły lub nie zostały przechwycone przez powolny dziennik zapytań. Sprawdź kartę Wydajność, jak pokazano poniżej,
te elementy zapewniają:
- Przegląd - Na tej stronie możesz przeglądać wykresy różnych liczników baz danych
- Doradcy — listy zaplanowanych wyników doradców utworzone w ClusterControl> Zarządzaj> Developer Studio przy użyciu ClusterControl DSL.
- Status bazy danych - Stan bazy danych zapewnia szybki przegląd stanu MySQL we wszystkich węzłach bazy danych, podobnie jak instrukcja SHOW STATUS
- Zmienne DB - Zmienne DB zapewniają szybki przegląd zmiennych MySQL, które są ustawione we wszystkich węzłach bazy danych, podobnie jak instrukcja SHOW GLOBAL VARIABLES
- Przyrost bazy danych — zawiera podsumowanie przyrostu bazy danych i tabeli w ciągu dnia w ciągu ostatnich 30 dni.
- Stan InnoDB — pobiera bieżące dane wyjściowe monitora InnoDB dla wybranego hosta, podobnie do polecenia SHOW ENGINE INNODB STATUS.
- Schema Analyzer — analizuje schematy bazy danych pod kątem brakujących kluczy podstawowych, nadmiarowych indeksów i tabel przy użyciu mechanizmu pamięci masowej MyISAM.
- Dziennik transakcji — zawiera listę długotrwałych transakcji i zakleszczeń w klastrze bazy danych, gdzie można łatwo sprawdzić, jakie transakcje powodują zakleszczenia. Domyślny próg czasu zapytania to 30 sekund.
Wnioski
Śledzenie problemu z wydajnością MySQL nie jest trudne w przypadku MySQL. Istnieją różne zewnętrzne narzędzia, które zapewniają wydajność i możliwości, których szukasz. Najważniejsze jest to, że jest łatwy w obsłudze i jesteś w stanie zapewnić produktywność w pracy. Napraw najbardziej nierozstrzygnięte problemy lub nawet uniknij pewnej katastrofy, zanim to się stanie.