sql >> Database >  >> RDS >> MariaDB

Problemen met MySQL-prestaties identificeren met trage zoekopdrachten

Prestatieproblemen zijn veelvoorkomende problemen bij het beheren van MySQL-databases. Soms zijn deze problemen in feite te wijten aan trage zoekopdrachten. In deze blog gaan we in op langzame zoekopdrachten en hoe u deze kunt identificeren.

Uw logbestanden voor langzame zoekopdrachten controleren

MySQL heeft de mogelijkheid om langzame zoekopdrachten te filteren en te loggen. Er zijn verschillende manieren om deze te onderzoeken, maar de meest gebruikelijke en efficiënte manier is om de trage querylogboeken te gebruiken.

U moet eerst bepalen of uw logbestanden voor langzame zoekopdrachten zijn ingeschakeld. Om dit aan te pakken, kunt u naar uw server gaan en de volgende variabele opvragen:

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)

U moet ervoor zorgen dat de variabele slow_query_log is ingesteld op ON, terwijl het slow_query_log_file het pad bepaalt waar u uw logbestanden voor trage zoekopdrachten moet plaatsen. Als deze variabele niet is ingesteld, gebruikt deze de DATA_DIR van uw MySQL-gegevensdirectory.

Vergezeld van de slow_query_log-variabele zijn de long_query_time en min_examined_row_limit die van invloed zijn op hoe de langzame logboekregistratie van query's werkt. In principe werken de trage querylogboeken als SQL-instructies die meer dan lange_query_time seconden nodig hebben om uit te voeren en die ook ten minste min_examined_row_limit rijen vereisen om te worden onderzocht. Het kan worden gebruikt om zoekopdrachten te vinden die veel tijd kosten om uit te voeren en daarom in aanmerking komen voor optimalisatie. Vervolgens kunt u externe tools gebruiken om het rapport voor u te maken, waarover later meer.

Administratieve instructies (ALTER TABLE, ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE en REPAIR TABLE) vallen niet in trage querylogboeken. Om dit te doen, moet u de variabele log_slow_admin_statements inschakelen.

Opvragen van proceslijst en InnoDB-statusmonitor

In een normale DBA-routine is deze stap de meest gebruikelijke manier om de langlopende query's of actief actieve query's te bepalen die prestatievermindering veroorzaken. Het kan er zelfs voor zorgen dat uw server vastloopt, gevolgd door opgestapelde wachtrijen die langzaam toenemen vanwege een vergrendeling die wordt afgedekt door een lopende query. Je kunt gewoon rennen,

SHOW [FULL] PROCESSLIST;

of

SHOW ENGINE INNODB STATUS \G

Als je ClusterControl gebruikt, kun je het vinden door → Query Monitor → Query's uitvoeren ( die later zal worden besproken) om de actieve processen te bekijken, net zoals een SHOW PROCESSLIST werkt, maar met een betere controle over de query's.

MySQL-query's analyseren

De logbestanden voor trage zoekopdrachten tonen u een lijst met zoekopdrachten die als traag zijn geïdentificeerd, op basis van de opgegeven waarden in de systeemvariabelen zoals eerder vermeld. De definitie van langzame zoekopdrachten kan in verschillende gevallen verschillen, omdat er bepaalde gelegenheden zijn dat zelfs een zoekopdracht van 10 seconden acceptabel is en nog steeds niet traag. Als uw toepassing echter een OLTP is, is het heel gebruikelijk dat een query van 10 seconden of zelfs 5 seconden een probleem is of de prestaties van uw database verslechtert. MySQL-querylog helpt u hierbij, maar het is niet voldoende om het logbestand te openen, omdat het u geen overzicht geeft van wat die query's zijn, hoe ze presteren en hoe vaak ze voorkomen. Daarom kunnen hulpprogramma's van derden u hierbij helpen.

pt-query-digest

Percona Toolkit gebruiken, waarvan ik kan zeggen dat het de meest gebruikelijke DBA-tool is, is om pt-query-digest te gebruiken. pt-query-digest biedt u een duidelijk overzicht van een specifiek rapport dat afkomstig is uit uw trage querylogboek. Dit specifieke rapport toont bijvoorbeeld een duidelijk perspectief voor het begrijpen van de trage queryrapporten in een specifiek knooppunt:

# 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

Performance_schema gebruiken

Langzame querylogboeken kunnen een probleem zijn als u geen directe toegang tot het bestand hebt, zoals het gebruik van RDS of het gebruik van volledig beheerde databaseservices zoals Google Cloud SQL of Azure SQL. Hoewel u misschien enkele variabelen nodig heeft om deze functies in te schakelen, is het handig bij het opvragen van query's die op uw systeem zijn ingelogd. U kunt het bestellen door een standaard SQL-instructie te gebruiken om een ​​gedeeltelijk resultaat op te halen. Bijvoorbeeld,

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 |

...

Je kunt de tabel performance_schema.events_statements_summary_by_digest gebruiken. Hoewel er een kans is dat de items op de tabellen van performance_schema gelijk zijn, kunt u besluiten dit in een specifieke tabel op te slaan. Bekijk dit externe bericht van Percona MySQL-querysamenvatting met prestatieschema.

In het geval je je afvraagt ​​waarom we de wachttijdkolommen moeten verdelen (SUM_TIMER_WAIT, MIN_TIMER_WAIT_SEC, AVG_TIMER_WAIT_SEC), deze kolommen gebruiken picoseconden, dus je moet misschien wat rekenwerk doen of wat afrondingen maken om het is beter leesbaar voor u.

Langzame zoekopdrachten analyseren met ClusterControl

Als je ClusterControl gebruikt, zijn er verschillende manieren om hiermee om te gaan. In een MariaDB-cluster die ik hieronder heb, ziet u bijvoorbeeld het volgende tabblad (Query Monitor) en de vervolgkeuzelijsten (Topquery's, Lopende query's, Query-uitschieters):

  • Topquery's -   geaggregeerde lijst van al uw topquery's die worden uitgevoerd op alle knooppunten van uw databasecluster
  • Lopende query's - Bekijk huidige lopende query's op uw databasecluster, vergelijkbaar met de opdracht SHOW FULL PROCESSLIST in MySQL
  • Uitbijters voor zoekopdrachten - Toont zoekopdrachten die uitbijters zijn. Een uitbijter is een zoekopdracht die langer duurt dan de normale zoekopdracht van dat type.

Bovendien legt ClusterControl ook de prestaties van zoekopdrachten vast met behulp van grafieken, zodat u snel kunt zien hoe uw databasesysteem presteert met betrekking tot de prestaties van de zoekopdracht. Zie hieronder,

Wacht, het is nog niet voorbij. ClusterControl biedt ook een metriek met hoge resolutie met behulp van Prometheus en toont zeer gedetailleerde statistieken en legt realtime statistieken van de server vast. We hebben dit besproken in onze vorige blogs die zijn onderverdeeld in twee blogreeksen. Bekijk deel 1 en dan de blogs van deel 2. Het biedt u informatie over hoe u niet alleen de langzame query's efficiënt kunt bewaken, maar ook de algehele prestaties van uw MySQL-, MariaDB- of Percona-databaseservers.

Er zijn ook andere hulpprogramma's in ClusterControl die aanwijzingen en hints geven die trage queryprestaties kunnen veroorzaken, zelfs als dit nog niet is gebeurd of nog niet is vastgelegd in het trage querylogboek. Bekijk het tabblad Prestaties zoals hieronder te zien is,

deze items bieden u het volgende:

  • Overzicht - U kunt op deze pagina grafieken van verschillende databasetellers bekijken
  • Advisors - Lijsten met geplande resultaten van adviseurs gemaakt in ClusterControl> Beheren> Developer Studio met ClusterControl DSL.
  • DB-status - DB-status biedt een snel overzicht van de MySQL-status voor al uw databaseknooppunten, vergelijkbaar met de SHOW STATUS-instructie
  • DB-variabelen - DB-variabelen bieden een snel overzicht van MySQL-variabelen die zijn ingesteld voor al uw databaseknooppunten, vergelijkbaar met de instructie SHOW GLOBAL VARIABLES
  • DB-groei - Biedt een samenvatting van uw database- en tabelgroei op dagelijkse basis voor de afgelopen 30 dagen.
  • InnoDB-status - Haalt de huidige InnoDB-monitoruitvoer op voor de geselecteerde host, vergelijkbaar met de opdracht SHOW ENGINE INNODB STATUS.
  • Schema Analyzer - Analyseert uw databaseschema's op ontbrekende primaire sleutels, redundante indexen en tabellen met behulp van de MyISAM-opslagengine.
  • Transactielogboek - Geeft een overzicht van langlopende transacties en impasses in het databasecluster, waar u gemakkelijk kunt zien welke transacties de impasses veroorzaken. De standaard drempel voor de querytijd is 30 seconden.

Conclusie

Het traceren van uw MySQL Performance-probleem is niet echt moeilijk met MySQL. Er zijn verschillende externe tools die u de efficiëntie en mogelijkheden bieden waarnaar u op zoek bent. Het belangrijkste is dat het gemakkelijk te gebruiken is en dat u productiviteit op het werk kunt bieden. Los de meest openstaande problemen op of vermijd zelfs een bepaalde ramp voordat deze kan plaatsvinden.


  1. SQL Server GUID-sorteeralgoritme. Waarom?

  2. SQL Server-query:snel met letterlijk maar traag met variabelen

  3. Bulk DELETE op SQL Server 2008 (Is er zoiets als Bulk Copy (bcp) voor het verwijderen van gegevens?)

  4. JSON_OBJECT() - Maak een JSON-object van een lijst met sleutel-/waardeparen in MySQL