MariaDB
 sql >> Database >  >> RDS >> MariaDB

Come identificare i problemi di prestazioni di MySQL con query lente

I problemi di prestazioni sono problemi comuni durante l'amministrazione di database MySQL. A volte questi problemi sono, in effetti, dovuti a query lente. In questo blog tratteremo le query lente e come identificarle.

Controllo dei registri delle query lente

MySQL ha la capacità di filtrare e registrare le query lente. Esistono vari modi per esaminarli, ma il modo più comune ed efficiente consiste nell'utilizzare i registri delle query lente.

Devi prima determinare se i log delle query lente sono abilitati. Per far fronte a questo, puoi andare sul tuo server e interrogare la seguente variabile:

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)

Devi assicurarti che la variabile slow_query_log sia impostata su ON, mentre slow_query_log_file determina il percorso in cui devi posizionare i log delle query lente. Se questa variabile non è impostata, utilizzerà DATA_DIR della directory dei dati MySQL.

Accompagnati dalla variabile slow_query_log ci sono long_query_time e min_examined_row_limit che influiscono sul funzionamento della registrazione lenta della query. Fondamentalmente, i registri delle query lente funzionano come istruzioni SQL che richiedono più di long_query_time secondi per essere eseguite e richiedono anche l'esame di almeno righe min_examined_row_limit. Può essere utilizzato per trovare query che richiedono molto tempo per essere eseguite e sono quindi candidate all'ottimizzazione e quindi puoi utilizzare strumenti esterni per portare il rapporto per te, che parlerà in seguito.

Per impostazione predefinita, le istruzioni amministrative (ALTER TABLE, ANALYZE TABLE, CHECK TABLE, CREATE INDEX, DROP INDEX, OPTIMIZE TABLE e REPAIR TABLE) non rientrano nei registri delle query lente. Per fare ciò, devi abilitare la variabile log_slow_admin_statements.

Lista dei processi di query e monitoraggio dello stato di InnoDB

In una normale routine DBA, questo passaggio è il modo più comune per determinare le query a esecuzione prolungata o le query attive in esecuzione che causano un degrado delle prestazioni. Potrebbe anche causare il blocco del server seguito da code accumulate che stanno aumentando lentamente a causa di un blocco coperto da una query in esecuzione. Puoi semplicemente correre,

SHOW [FULL] PROCESSLIST;

o

SHOW ENGINE INNODB STATUS \G

Se stai usando ClusterControl, puoi trovarlo usando → Query Monitor → Esecuzione di query ( di cui parleremo più avanti) per visualizzare i processi attivi, proprio come funziona SHOW PROCESSLIST ma con un migliore controllo delle query.

Analisi delle query MySQL

I log delle query lente ti mostreranno un elenco di query che sono state identificate come lente, in base ai valori forniti nelle variabili di sistema come menzionato in precedenza. La definizione di query lente potrebbe differire in casi diversi poiché in alcune occasioni anche una query di 10 secondi è accettabile e non lenta. Tuttavia, se l'applicazione è un OLTP, è molto comune che una query di 10 secondi o anche di 5 secondi sia un problema o causi un degrado delle prestazioni del database. Il log delle query MySQL ti aiuta in questo, ma non è sufficiente aprire il file di registro in quanto non fornisce una panoramica di quali sono queste query, come funzionano e qual è la frequenza con cui si verificano. Pertanto, gli strumenti di terze parti possono aiutarti con questi.

pt-query-digest

L'uso di Percona Toolkit, che posso dire lo strumento DBA più comune, consiste nell'usare pt-query-digest. pt-query-digest fornisce una panoramica chiara di un report specifico proveniente dal registro delle query lente. Ad esempio, questo rapporto specifico mostra una prospettiva chiara di comprensione dei rapporti di query lente in un nodo specifico:

# 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

Utilizzo di performance_schema

I log di query lenti potrebbero essere un problema se non si dispone dell'accesso diretto al file, ad esempio utilizzando RDS o utilizzando servizi di database completamente gestiti come Google Cloud SQL o Azure SQL. Sebbene potrebbero essere necessarie alcune variabili per abilitare queste funzionalità, è utile quando si eseguono query per query registrate nel sistema. Puoi ordinarlo utilizzando un'istruzione SQL standard per recuperare un risultato parziale. Ad esempio,

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 |

...

Puoi usare la tabella performance_schema.events_statements_summary_by_digest. Sebbene ci siano possibilità che le voci sulle tabelle da performance_schema siano a filo, puoi decidere di salvarlo in una tabella specifica. Dai un'occhiata a questo post esterno da Percona MySQL query digest con Performance Schema.

Nel caso ti stia chiedendo perché dobbiamo dividere le colonne del tempo di attesa (SUM_TIMER_WAIT, MIN_TIMER_WAIT_SEC, AVG_TIMER_WAIT_SEC), queste colonne usano i picosecondi, quindi potresti dover fare un po' di calcoli o arrotondare per eccesso per fare sarà più leggibile per te.

Analisi di query lente utilizzando ClusterControl

Se stai usando ClusterControl, ci sono diversi modi per gestirlo. Ad esempio, in un cluster MariaDB che ho di seguito, mostra la seguente scheda (Query Monitor) e i suoi elementi a discesa (Top Query, Running Query, Query Outliers):

  • Principali query: elenco aggregato di tutte le principali query in esecuzione su tutti i nodi del tuo cluster di database
  • Query in esecuzione:visualizza le query in esecuzione sul cluster di database in modo simile al comando SHOW FULL PROCESSLIST in MySQL
  • Query valori anomali:mostra le query che sono valori anomali. Un valore anomalo è una query che richiede più tempo rispetto alla normale query di quel tipo.

Inoltre, ClusterControl acquisisce anche le prestazioni delle query utilizzando grafici che forniscono una rapida panoramica delle prestazioni del sistema di database in relazione alle prestazioni delle query. Vedi sotto,

Aspetta, non è ancora finita. ClusterControl offre anche una metrica ad alta risoluzione utilizzando Prometheus, mostra metriche molto dettagliate e acquisisce statistiche in tempo reale dal server. Ne abbiamo discusso nei nostri blog precedenti che sono divisi in due serie di blog. Dai un'occhiata alla parte 1 e poi ai blog della parte 2. Ti offre come monitorare in modo efficiente non solo le query lente, ma anche le prestazioni complessive dei tuoi server di database MySQL, MariaDB o Percona.

Ci sono anche altri strumenti in ClusterControl che forniscono puntatori e suggerimenti che possono causare un rallentamento delle prestazioni delle query anche se non sono ancora verificati o catturati dal registro delle query lente. Dai un'occhiata alla scheda Performance come mostrato di seguito,

questi elementi forniscono quanto segue:

  • Panoramica:in questa pagina puoi visualizzare i grafici di diversi contatori di database
  • Advisor - Elenchi dei risultati degli advisor programmati creati in ClusterControl> Gestisci> Developer Studio utilizzando ClusterControl DSL.
  • Stato DB - Lo stato DB fornisce una rapida panoramica dello stato di MySQL in tutti i nodi del database, in modo simile all'istruzione SHOW STATUS
  • Variabili DB - Le variabili DB forniscono una rapida panoramica delle variabili MySQL impostate su tutti i nodi del database, in modo simile all'istruzione SHOW GLOBAL VARIABLES
  • Crescita database:fornisce un riepilogo della crescita del database e della tabella su base giornaliera negli ultimi 30 giorni.
  • Stato InnoDB:recupera l'output del monitor InnoDB corrente per l'host selezionato, in modo simile al comando SHOW ENGINE INNODB STATUS.
  • Schema Analyzer:analizza gli schemi del database alla ricerca di chiavi primarie, indici ridondanti e tabelle mancanti utilizzando il motore di archiviazione MyISAM.
  • Registro delle transazioni:elenca le transazioni e i deadlock di lunga durata nel cluster di database in cui è possibile visualizzare facilmente quali transazioni stanno causando i deadlock. La soglia del tempo di query predefinita è 30 secondi.

Conclusione

Tracciare il tuo problema di prestazioni di MySQL non è molto difficile con MySQL. Esistono vari strumenti esterni che ti forniscono l'efficienza e le capacità che stai cercando. La cosa più importante è che è facile da usare e sei in grado di fornire produttività sul lavoro. Risolvi i problemi più in sospeso o addirittura evita un certo disastro prima che possa accadere.