Prestandaproblem är vanliga problem vid administrering av MySQL-databaser. Ibland beror dessa problem i själva verket på långsamma frågor. I den här bloggen kommer vi att ta itu med långsamma frågor och hur man identifierar dessa.
Kontrollera dina långsamma frågeloggar
MySQL har förmågan att filtrera och logga långsamma frågor. Det finns olika sätt du kan undersöka dessa på, men det vanligaste och mest effektiva sättet är att använda de långsamma frågeloggarna.
Du måste först avgöra om dina långsamma frågeloggar är aktiverade. För att hantera detta kan du gå till din server och fråga efter följande 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 måste se till att variabeln slow_query_log är inställd på ON, medan slow_query_log_filen bestämmer sökvägen dit du behöver placera dina långsamma frågeloggar. Om denna variabel inte är inställd kommer den att använda DATA_DIR i din MySQL-datakatalog.
Attföljs av variabeln slow_query_log är long_query_time och min_examined_row_limit som påverkar hur den långsamma frågeloggningen fungerar. I grund och botten fungerar de långsamma frågeloggarna som SQL-satser som tar mer än long_query_time sekunder att exekvera och även kräver att minst min_examined_row_limit-rader undersöks. Den kan användas för att hitta frågor som tar lång tid att köra och därför är kandidater för optimering och sedan kan du använda externa verktyg för att ta fram rapporten åt dig, som kommer att pratas senare.
Som standard faller inte administrativa uttalanden (ÄNDRA TABELL, ANALYSE TABELL, KONTROLLTABELL, SKAPA INDEX, SLIPPA INDEX, OPTIMERA TABELL och REPARERA TABELL) i långsamma frågeloggar. För att göra detta måste du aktivera variabel log_slow_admin_statements.
Frågeprocesslista och InnoDB Status Monitor
I en normal DBA-rutin är det här steget det vanligaste sättet att fastställa de långa pågående frågorna eller aktiva pågående frågorna som orsakar prestandaförsämring. Det kan till och med leda till att din server fastnar följt av staplade köer som långsamt ökar på grund av ett lås som täcks av en pågående fråga. Du kan helt enkelt springa,
SHOW [FULL] PROCESSLIST;eller
SHOW ENGINE INNODB STATUS \GOm du använder ClusterControl kan du hitta det genom att använda
eller använd
Analysera MySQL-frågor
De långsamma frågeloggarna visar dig en lista över frågor som har identifierats som långsamma, baserat på de givna värdena i systemvariablerna som nämnts tidigare. Definitionen av långsamma frågor kan skilja sig åt i olika fall eftersom det finns vissa tillfällen då även en 10 sekunder lång fråga är acceptabel och fortfarande inte långsam. Men om din applikation är en OLTP, är det mycket vanligt att en 10 sekunders eller till och med en 5 sekunders fråga är ett problem eller orsakar prestandaförsämring av din databas. MySQL-frågelogg hjälper dig detta men det räcker inte att öppna loggfilen eftersom den inte ger dig en översikt över vad dessa frågor är, hur de fungerar och hur ofta de förekommer. Därför kan tredjepartsverktyg hjälpa dig med dessa.
pt-query-digest
Att använda Percona Toolkit, som jag kan säga är det vanligaste DBA-verktyget, är att använda pt-query-digest. pt-query-digest ger dig en ren översikt över en specifik rapport som kommer från din långsamma frågelogg. Till exempel visar den här specifika rapporten ett rent perspektiv på att förstå de långsamma frågerapporterna i en specifik nod:
# 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\GAnvända performance_schema
Långsamma frågeloggar kan vara ett problem om du inte har direktåtkomst till filen som att använda RDS eller använda helt hanterade databastjänster som Google Cloud SQL eller Azure SQL. Även om det kan behöva några variabler för att aktivera dessa funktioner, är det praktiskt när du frågar efter frågor som är inloggade på ditt system. Du kan beställa den genom att använda en standard SQL-sats för att hämta ett delresultat. Till exempel,
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 använda tabellen performance_schema.events_statements_summary_by_digest. Även om det finns chanser att posterna i tabellerna från performance_schema kommer att vara flush, kan du välja att spara detta i en specifik tabell. Ta en titt på det här externa inlägget från Percona MySQL-frågesammandrag med Performance Schema.
Om du undrar varför vi behöver dela upp väntetidskolumnerna (SUM_TIMER_WAIT, MIN_TIMER_WAIT_SEC, AVG_TIMER_WAIT_SEC), använder dessa kolumner pikosekunder, så du kan behöva göra lite matematik eller några avrundningar för att göra den är mer läsbar för dig.
Analysera långsamma frågor med ClusterControl
Om du använder ClusterControl finns det olika sätt att hantera detta. Till exempel, i ett MariaDB-kluster som jag har nedan, visar det dig följande flik (Query Monitor) och dess rullgardinsobjekt (Top Queries, Running Queries, Query Outliers):
- Topfrågor – sammanställd lista över alla dina vanligaste frågor som körs på alla noder i ditt databaskluster
- Körande frågor - Visa aktuella frågor som körs i ditt databaskluster liknande kommandot SHOW FULL PROCESSLIST i MySQL
- Frågeavvikelser – Visar frågor som är extremvärden. En outlier är en fråga som tar längre tid än den normala frågan av den typen.
Utöver detta fångar ClusterControl också frågeprestanda med hjälp av grafer som ger dig en snabb överblick över hur ditt databassystem presterar i förhållande till frågeprestanda. Se nedan,
Vänta, det är inte över än. ClusterControl erbjuder också ett högupplöst mått med hjälp av Prometheus och visar mycket detaljerade mått och fångar in realtidsstatistik från servern. Vi har diskuterat detta i våra tidigare bloggar som är uppdelade i två delar av bloggserier. Kolla in del 1 och sedan del 2 bloggar. Den ger dig information om hur du effektivt övervakar inte bara de långsamma frågorna utan den övergripande prestandan för dina MySQL-, MariaDB- eller Percona-databasservrar.
Det finns även andra verktyg i ClusterControl som ger pekare och tips som kan orsaka långsam frågeprestanda även om det ännu inte har inträffat eller fångat upp av den långsamma frågeloggen. Kolla in prestandafliken som visas nedan,
dessa objekt ger dig följande:
- Översikt - Du kan se grafer över olika databasräknare på den här sidan
- Rådgivare – Listor över schemalagda rådgivares resultat skapade i ClusterControl> Hantera> Developer Studio med ClusterControl DSL.
- DB-status – DB-status ger en snabb översikt över MySQL-status över alla dina databasnoder, liknande SHOW STATUS-satsen
- DB-variabler – DB-variabler ger en snabb översikt över MySQL-variabler som ställs in över alla dina databasnoder, liknande SHOW GLOBAL VARIABLES-satsen
- DB-tillväxt - Ger en sammanfattning av din databas- och tabelltillväxt på daglig basis under de senaste 30 dagarna.
- InnoDB Status - Hämtar den aktuella InnoDB-monitorns utdata för den valda värddatorn, liknande kommandot SHOW ENGINE INNODB STATUS.
- Schema Analyzer - Analyserar dina databasscheman för saknade primärnycklar, redundanta index och tabeller med hjälp av MyISAM-lagringsmotorn.
- Transaktionslogg - Listar ut långvariga transaktioner och låsningar över databaskluster där du enkelt kan se vilka transaktioner som orsakar låsningarna. Standardtröskeln för frågetid är 30 sekunder.
Slutsats
Att spåra ditt MySQL-prestandaproblem är inte riktigt svårt med MySQL. Det finns olika externa verktyg som ger dig den effektivitet och kapacitet som du letar efter. Det viktigaste är att det är lätt att använda och du kan ge produktivitet på jobbet. Åtgärda de mest utestående problemen eller till och med undvik en viss katastrof innan den kan hända.