Ydeevneproblemer er almindelige problemer ved administration af MySQL-databaser. Nogle gange skyldes disse problemer faktisk langsomme forespørgsler. I denne blog vil vi behandle langsomme forespørgsler, og hvordan man identificerer disse.
Tjek dine langsomme forespørgselslogfiler
MySQL har evnen til at filtrere og logge langsomme forespørgsler. Der er forskellige måder, du kan undersøge disse på, men den mest almindelige og effektive måde er at bruge de langsomme forespørgselslogfiler.
Du skal først afgøre, om dine langsomme forespørgselslogfiler er aktiveret. For at håndtere dette kan du gå til din server og forespørge på følgende variabel:
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)Du skal sikre dig, at variablen slow_query_log er sat til ON, mens slow_query_log_filen bestemmer stien, hvor du skal placere dine langsomme forespørgselslogfiler. Hvis denne variabel ikke er indstillet, vil den bruge DATA_DIR i din MySQL-datamappe.
Akkompagneret af slow_query_log-variablen er long_query_time og min_examined_row_limit, som påvirker, hvordan den langsomme forespørgselslogning fungerer. Grundlæggende fungerer de langsomme forespørgselslogfiler som SQL-sætninger, der tager mere end long_query_time sekunder at udføre, og som også kræver, at mindst min_examined_row_limit rækker skal undersøges. Det kan bruges til at finde forespørgsler, der tager lang tid at udføre og derfor er kandidater til optimering, og så kan du bruge eksterne værktøjer til at bringe rapporten til dig, som vil tale senere.
Som standard falder administrative udsagn (ALTER TABLE, ANALYSE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE og REPARATION TABLE) ikke ind i langsomme forespørgselslogfiler. For at gøre dette skal du aktivere variabel log_slow_admin_statements.
Forespørgselsprocesliste og InnoDB Status Monitor
I en normal DBA-rutine er dette trin den mest almindelige måde at bestemme de langvarige forespørgsler eller aktive kørende forespørgsler, der forårsager ydeevneforringelse. Det kan endda få din server til at sidde fast efterfulgt af ophobede køer, der langsomt stiger på grund af en lås, der er dækket af en kørende forespørgsel. Du kan bare løbe,
SHOW [FULL] PROCESSLIST;eller
SHOW ENGINE INNODB STATUS \GHvis du bruger ClusterControl, kan du finde den ved at bruge
eller brug
Analyse af MySQL-forespørgsler
De langsomme forespørgselslogfiler viser dig en liste over forespørgsler, der er blevet identificeret som langsomme, baseret på de givne værdier i systemvariablerne som nævnt tidligere. Definitionen af langsomme forespørgsler kan variere i forskellige tilfælde, da der er visse tilfælde, hvor selv en forespørgsel på 10 sekunder er acceptabel og stadig ikke langsom. Men hvis din applikation er en OLTP, er det meget almindeligt, at en 10 sekunders eller endda en 5 sekunders forespørgsel er et problem eller forårsager ydeevneforringelse af din database. MySQL-forespørgselslog hjælper dig med dette, men det er ikke nok at åbne logfilen, da den ikke giver dig et overblik over, hvad disse forespørgsler er, hvordan de fungerer, og hvor ofte de forekommer. Derfor kan tredjepartsværktøjer hjælpe dig med disse.
pt-query-digest
At bruge Percona Toolkit, som jeg kan sige det mest almindelige DBA-værktøj, er at bruge pt-query-digest. pt-query-digest giver dig et rent overblik over en specifik rapport, der kommer fra din langsomme forespørgselslog. For eksempel viser denne specifikke rapport et rent perspektiv på at forstå de langsomme forespørgselsrapporter i en specifik node:
# 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\GBrug af performance_schema
Langsomme forespørgselslogfiler kan være et problem, hvis du ikke har direkte adgang til filen, såsom at bruge RDS eller bruge fuldt administrerede databasetjenester såsom Google Cloud SQL eller Azure SQL. Selvom det måske har brug for dig nogle variabler for at aktivere disse funktioner, er det praktisk, når du forespørger efter forespørgsler, der er logget ind på dit system. Du kan bestille det ved at bruge en standard SQL-sætning for at hente et delvist resultat. For eksempel,
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 |
...Du kan bruge tabellen performance_schema.events_statements_summary_by_digest. Selvom der er chancer for, at indtastningerne i tabellerne fra performance_schema vil blive flush, kan du beslutte at gemme dette i en specifik tabel. Tag et kig på dette eksterne indlæg fra Percona MySQL-forespørgselssammendrag med Performance Schema.
Hvis du undrer dig over, hvorfor vi skal opdele ventetidskolonnerne (SUM_TIMER_WAIT, MIN_TIMER_WAIT_SEC, AVG_TIMER_WAIT_SEC), bruger disse kolonner picosekunder, så du skal muligvis lave nogle matematiske beregninger eller runde op. den er mere læsbar for dig.
Analyse af langsomme forespørgsler ved hjælp af ClusterControl
Hvis du bruger ClusterControl, er der forskellige måder at håndtere dette på. For eksempel, i en MariaDB-klynge, jeg har nedenfor, viser den dig følgende fane (Forespørgselsmonitor) og dens rullemenupunkter (Topforespørgsler, Kørende forespørgsler, Forespørgselsudligninger):
- Topforespørgsler - samlet liste over alle dine topforespørgsler, der kører på alle noderne i din databaseklynge
- Kørende forespørgsler - Se aktuelle kørende forespørgsler på din databaseklynge svarende til kommandoen SHOW FULL PROCESSLIST i MySQL
- Forespørgsels-outliers - Viser forespørgsler, der er outliers. En outlier er en forespørgsel, der tager længere tid end den normale forespørgsel af den type.
Oven i købet fanger ClusterControl også forespørgselsydeevne ved hjælp af grafer, som giver dig et hurtigt overblik over, hvordan dit databasesystem præsterer i forhold til forespørgselsydeevne. Se nedenfor,
Vent, det er ikke slut endnu. ClusterControl tilbyder også en metrik i høj opløsning ved hjælp af Prometheus og viser meget detaljerede målinger og fanger realtidsstatistikker fra serveren. Vi har diskuteret dette i vores tidligere blogs, som er opdelt i to delserier af blog. Tjek del 1 og derefter del 2 blogs. Det giver dig information om, hvordan du effektivt overvåger ikke kun de langsomme forespørgsler, men den overordnede ydeevne af dine MySQL-, MariaDB- eller Percona-databaseservere.
Der er også andre værktøjer i ClusterControl, som giver pointer og hints, der kan forårsage langsom forespørgselsydeevne, selvom det endnu ikke er fundet eller fanget af den langsomme forespørgselslog. Tjek fanen Ydelse som vist nedenfor,
disse elementer giver dig følgende:
- Oversigt - Du kan se grafer over forskellige databasetællere på denne side
- Rådgivere - Lister over planlagte rådgiveres resultater oprettet i ClusterControl> Administrer> Developer Studio ved hjælp af ClusterControl DSL.
- DB-status – DB-status giver et hurtigt overblik over MySQL-status på tværs af alle dine databasenoder, svarende til SHOW STATUS-sætning
- DB-variabler - DB-variabler giver et hurtigt overblik over MySQL-variabler, der er sat på tværs af alle dine databasenoder, svarende til SHOW GLOBAL VARIABLES-sætningen
- DB-vækst - Giver en oversigt over din database- og tabelvækst på daglig basis for de sidste 30 dage.
- InnoDB-status - Henter det aktuelle InnoDB-monitoroutput for valgt vært, svarende til kommandoen SHOW ENGINE INNODB STATUS.
- Skemaanalysator - Analyserer dine databaseskemaer for manglende primærnøgler, redundante indekser og tabeller ved hjælp af MyISAM-lagringsmotoren.
- Transaktionslog - Viser langvarige transaktioner og deadlocks på tværs af databaseklynge, hvor du nemt kan se, hvilke transaktioner der forårsager deadlocks. Standardtærsklen for forespørgselstid er 30 sekunder.
Konklusion
Det er ikke rigtig svært at spore dit MySQL-ydelsesproblem med MySQL. Der er forskellige eksterne værktøjer, der giver dig den effektivitet og de muligheder, som du leder efter. Det vigtigste er, at det er nemt at bruge, og du er i stand til at levere produktivitet på arbejdet. Løs de mest udestående problemer eller undgå endda en bestemt katastrofe, før det kan ske.