Un peu d'histoire, il y a quelque temps, nous avons commencé à connaître un temps système CPU élevé sur l'une de nos bases de données MySQL. Cette base de données souffrait également d'une utilisation élevée du disque, nous avons donc pensé que ces choses étaient connectées. Et comme nous avions déjà prévu de le migrer vers le SSD, nous pensions qu'il résoudrait les deux problèmes.
Ça a aidé ... mais pas pour longtemps.
Pendant quelques semaines après la migration, le graphique du processeur était le suivant:
Mais maintenant, nous y revenons:
Cela s'est produit de nulle part, sans aucun changement apparent dans la logique de charge ou d'application.
Statistiques DB:
- Version MySQL - 5.7.20
- OS - Debian
- Taille DB - 1,2 To
- RAM - 700 Go
- Cœurs de processeur - 56
- Charge de lecture - environ 5kq / s en lecture, 600q / s en écriture (bien que certaines requêtes soient souvent assez complexes)
- Fils - 50 en cours d'exécution, 300 connectés
- Il a environ 300 tables, toutes InnoDB
Configuration MySQL:
[client]
port = 3306
socket = /var/run/mysqld/mysqld.sock
[mysqld_safe]
pid-file = /var/run/mysqld/mysqld.pid
socket = /var/run/mysqld/mysqld.sock
nice = 0
[mysqld]
user = mysql
pid-file = /var/run/mysqld/mysqld.pid
socket = /var/run/mysqld/mysqld.sock
port = 3306
basedir = /usr
datadir = /opt/mysql-data
tmpdir = /tmp
lc-messages-dir = /usr/share/mysql
explicit_defaults_for_timestamp
sql_mode = STRICT_TRANS_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION
log-error = /opt/mysql-log/error.log
# Replication
server-id = 76
gtid-mode = ON
enforce-gtid-consistency = true
relay-log = /opt/mysql-log/mysql-relay-bin
relay-log-index = /opt/mysql-log/mysql-relay-bin.index
replicate-wild-do-table = dbname.%
log-bin = /opt/mysql-log/mysql-bin.log
expire_logs_days = 7
max_binlog_size = 1024M
binlog-format = ROW
log-bin-trust-function-creators = 1
log_slave_updates = 1
# Disabling symbolic-links is recommended to prevent assorted security risks
symbolic-links=0
# * IMPORTANT: Additional settings that can override those from this file!
# The files must end with '.cnf', otherwise they'll be ignored.
#
!includedir /etc/mysql/conf.d/
# Here goes
skip_name_resolve = 1
general_log = 0
slow_query_log = 1
slow_query_log_file = /opt/mysql-log/slow.log
long_query_time = 3
max_allowed_packet = 16M
max_connections = 700
max_execution_time = 200000
open_files_limit = 32000
table_open_cache = 8000
thread_cache_size = 128
innodb_buffer_pool_size = 550G
innodb_buffer_pool_instances = 28
innodb_log_file_size = 15G
innodb_log_files_in_group = 2
innodb_flush_method = O_DIRECT
max_heap_table_size = 16M
tmp_table_size = 128M
join_buffer_size = 1M
sort_buffer_size = 2M
innodb_lru_scan_depth = 256
query_cache_type = 0
query_cache_size = 0
innodb_temp_data_file_path = ibtmp1:12M:autoextend:max:30G Autres observations
perf du processus mysql pendant la charge de pointe:
68,31% 68,31% mysqld [kernel.kallsyms] [k] _raw_spin_lock
- _raw_spin_lock
+ 51,63% 0x7fd118e9dbd9
+ 48,37% 0x7fd118e9dbab
+ 37,36% 0,02% mysqld libc-2.19.so [.] 0x00000000000f4bd9
+ 33,83% 0,01% mysqld libc-2.19.so [.] 0x00000000000f4bab
+ 26,92% 0,00% mysqld libpthread-2.19.so [.] start_thread
+ 26,82% 0,00% mysqld mysqld [.] pfs_spawn_thread
+ 26,82% 0,00% mysqld mysqld [.] handle_connection
+ 26,81% 0,01% mysqld mysqld [.] do_command(THD*)
+ 26,65% 0,02% mysqld mysqld [.] dispatch_command(THD*, COM_DATA const*, enum_server_command)
+ 26,29% 0,01% mysqld mysqld [.] mysql_parse(THD*, Parser_state*)
+ 24,85% 0,01% mysqld mysqld [.] mysql_execute_command(THD*, bool)
+ 23,61% 0,00% mysqld mysqld [.] handle_query(THD*, LEX*, Query_result*, unsigned long long, unsigned long long)
+ 23,54% 0,00% mysqld mysqld [.] 0x0000000000374103
+ 19,78% 0,00% mysqld mysqld [.] JOIN::exec()
+ 19,13% 0,15% mysqld mysqld [.] sub_select(JOIN*, QEP_TAB*, bool)
+ 13,86% 1,48% mysqld mysqld [.] row_search_mvcc(unsigned char*, page_cur_mode_t, row_prebuilt_t*, unsigned long, unsigned long)
+ 8,48% 0,25% mysqld mysqld [.] ha_innobase::general_fetch(unsigned char*, unsigned int, unsigned int)
+ 7,93% 0,00% mysqld [unknown] [.] 0x00007f40c4d7a6f8
+ 7,57% 0,00% mysqld mysqld [.] 0x0000000000828f74
+ 7,25% 0,11% mysqld mysqld [.] handler::ha_index_next_same(unsigned char*, unsigned char const*, unsigned int) Cela montre que mysql passe beaucoup de temps sur spin_locks . J'espérais avoir un indice sur la provenance de ces serrures, malheureusement, pas de chance.
Le profil de requête pendant une charge élevée montre une quantité extrême de changements de contexte. J'ai utilisé select * de MyTable où pk = 123 , MyTable a environ 90M lignes. Sortie de profil:
Status Duration CPU_user CPU_system Context_voluntary Context_involuntary Block_ops_in Block_ops_out Messages_sent Messages_received Page_faults_major Page_faults_minor Swaps Source_function Source_file Source_line
starting 0,000756 0,028000 0,012000 81 1 0 0 0 0 0 0 0
checking permissions 0,000057 0,004000 0,000000 4 0 0 0 0 0 0 0 0 check_access sql_authorization.cc 810
Opening tables 0,000285 0,008000 0,004000 31 0 0 40 0 0 0 0 0 open_tables sql_base.cc 5650
init 0,000304 0,012000 0,004000 31 1 0 0 0 0 0 0 0 handle_query sql_select.cc 121
System lock 0,000303 0,012000 0,004000 33 0 0 0 0 0 0 0 0 mysql_lock_tables lock.cc 323
optimizing 0,000196 0,008000 0,004000 20 0 0 0 0 0 0 0 0 optimize sql_optimizer.cc 151
statistics 0,000885 0,036000 0,012000 99 6 0 0 0 0 0 0 0 optimize sql_optimizer.cc 367
preparing 0,000794 0,000000 0,096000 76 2 32 8 0 0 0 0 0 optimize sql_optimizer.cc 475
executing 0,000067 0,000000 0,000000 10 1 0 0 0 0 0 0 0 exec sql_executor.cc 119
Sending data 0,000469 0,000000 0,000000 54 1 32 0 0 0 0 0 0 exec sql_executor.cc 195
end 0,000609 0,000000 0,016000 64 4 0 0 0 0 0 0 0 handle_query sql_select.cc 199
query end 0,000063 0,000000 0,000000 3 1 0 0 0 0 0 0 0 mysql_execute_command sql_parse.cc 4968
closing tables 0,000156 0,000000 0,000000 20 4 0 0 0 0 0 0 0 mysql_execute_command sql_parse.cc 5020
freeing items 0,000071 0,000000 0,004000 7 1 0 0 0 0 0 0 0 mysql_parse sql_parse.cc 5596
cleaning up 0,000533 0,024000 0,008000 62 0 0 0 0 0 0 0 0 dispatch_command sql_parse.cc 1902Peter Zaitsev a récemment publié un article sur les changements de contexte, où il dit:
Dans le monde réel, cependant, je ne craindrais pas que la contention soit un gros problème si vous avez moins de dix changements de contexte par requête.
Mais il affiche plus de 600 commutateurs!
Qu'est-ce qui peut provoquer ces symptômes et que peut-on faire pour y remédier? J'apprécierai tous les conseils ou informations sur la question, tout ce que je rencontre jusqu'à présent est plutôt ancien et / ou peu concluant.
PS Je me ferai un plaisir de fournir des informations supplémentaires, si nécessaire.
Sortie de SHOW GLOBAL STATUS et SHOW VARIABLES
Je ne peux pas le publier ici car le contenu dépasse la limite de taille du message.
AFFICHER LE STATUT MONDIAL
AFFICHER LES VARIABLES
iostat
avg-cpu: %user %nice %system %iowait %steal %idle
7,35 0,00 5,44 0,20 0,00 87,01
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
fd0 0,00 0,00 0,00 0,00 0,00 0,00 8,00 0,00 32,00 32,00 0,00 32,00 0,00
sda 0,04 2,27 0,13 0,96 0,86 46,52 87,05 0,00 2,52 0,41 2,80 0,28 0,03
sdb 0,21 232,57 30,86 482,91 503,42 7769,88 32,21 0,34 0,67 0,83 0,66 0,34 17,50
avg-cpu: %user %nice %system %iowait %steal %idle
9,98 0,00 77,52 0,46 0,00 12,04
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
fd0 0,00 0,00 0,00 0,00 0,00 0,00 0,00 0,00 0,00 0,00 0,00 0,00 0,00
sda 0,00 1,60 0,00 0,60 0,00 8,80 29,33 0,00 0,00 0,00 0,00 0,00 0,00
sdb 0,00 566,40 55,60 981,60 889,60 16173,60 32,90 0,84 0,81 0,76 0,81 0,51 53,28
avg-cpu: %user %nice %system %iowait %steal %idle
11,83 0,00 72,72 0,35 0,00 15,10
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
fd0 0,00 0,00 0,00 0,00 0,00 0,00 0,00 0,00 0,00 0,00 0,00 0,00 0,00
sda 0,00 2,60 0,00 0,40 0,00 12,00 60,00 0,00 0,00 0,00 0,00 0,00 0,00
sdb 0,00 565,20 51,60 962,80 825,60 15569,60 32,32 0,85 0,84 0,98 0,83 0,54 54,56Mise à jour 2018-03-15
> show global status like 'uptime%'
Uptime;720899
Uptime_since_flush_status;720899
> show global status like '%rollback'
Com_rollback;351422
Com_xa_rollback;0
Handler_rollback;371088
Handler_savepoint_rollback;0
select * from MyTable where pk = 123prend en moyenne?global statuspour voir si quelque chose est en corrélation avec l'augmentation de l'utilisation du CPU. Je ne crois pas que quelque chose puisse être réalisé avec les données disponibles pour le moment. Je poserai une autre question si je trouve quelque chose de nouveau.Réponses:
L'écriture à 600 q / s avec un vidage par commit atteint probablement la limite de vos disques en rotation actuels. Le passage aux SSD soulagerait la pression.
La solution rapide (avant d'obtenir des SSD) consiste probablement à modifier ce paramètre:
Mais lisez les mises en garde sur ce changement.
Avoir ce paramètre et ces SSD vous permettrait de vous développer davantage.
Une autre solution possible consiste à combiner certaines écritures en une seule
COMMIT(où la logique n'est pas violée).Presque toujours, un CPU et / ou des E / S élevés sont dus à de mauvais index et / ou à une mauvaise formulation des requêtes. Activez le slowlog avec
long_query_time=1, attendez un moment, puis voyez ce qui se passe. Avec des requêtes à la main, fournirSELECT,EXPLAIN SELECT ...etSHOW CREATE TABLE. Idem pour les requêtes d'écriture. De ceux-ci, nous pouvons probablement apprivoiser le CPU et / ou les E / S. Même avec votre configuration actuelle3, vouspt-query-digestpourriez trouver des choses intéressantes.Notez qu'avec 50 threads "en cours d'exécution", il y a beaucoup de conflits; cela peut être à l'origine du changement, etc., que vous avez noté. Nous devons obtenir des requêtes pour terminer plus rapidement. Avec 5.7, le système peut déborder avec 100 threads en cours d' exécution. Au-delà d'environ 64, les commutateurs de contexte, les mutex, les verrous, etc., conspirent pour ralentir chaque thread, n'entraînant aucune amélioration du débit pendant que la latence passe par le toit.
Pour une approche différente de l'analyse du problème, veuillez fournir
SHOW VARIABLESetSHOW GLOBAL STATUS? Plus de discussion ici .Analyse des VARIABLES & STATUS
(Désolé, rien ne ressort comme répondant à votre question.)
Observations:
Les problèmes les plus importants:
De nombreuses tables temporaires, en particulier sur disque, sont créées pour des requêtes complexes. Espérons que le journal lent identifiera certaines requêtes qui peuvent être améliorées (via l'indexation / la reformulation / etc.) D'autres indicateurs sont des jointures sans index et sort_merge_passes; cependant, ni l'un ni l'autre n'est concluant, nous devons voir les requêtes.
Max_used_connections = 701est> =Max_connections = 700, il y avait donc probablement des connexions refusées. En outre, si cela indiquait plus de, disons, 64 threads en cours d'exécution , les performances du système en souffraient probablement à ce moment-là. Envisagez de limiter le nombre de connexions en limitant les clients. Utilisez-vous Apache, Tomcat ou autre chose? 70Threads_runningindique qu'au moment de le faireSHOW, le système était en difficulté.L'augmentation du nombre d'instructions dans chacune
COMMIT(lorsque cela est raisonnable) peut aider à la performance.innodb_log_file_size, à 15 Go, est plus grand que nécessaire, mais je ne vois pas besoin de le changer.Des milliers de tables ne sont généralement pas une bonne conception.
eq_range_index_dive_limit = 200me concerne, mais je ne sais pas comment conseiller. Était-ce un choix délibéré?Pourquoi tant de PROCEDURE CREATE + DROP?
Pourquoi tant de commandes SHOW?
Détails et autres observations:
( Innodb_buffer_pool_pages_flushed ) = 523,716,598 / 3158494 = 165 /sec- Écrit (rince) - vérifiez innodb_buffer_pool_size( table_open_cache ) = 10,000- Nombre de descripteurs de table à mettre en cache - Plusieurs centaines est généralement bon.( (Innodb_buffer_pool_reads + Innodb_buffer_pool_pages_flushed) ) = ((61,040,718 + 523,716,598) ) / 3158494 = 185 /sec- E / S InnoDB( Innodb_dblwr_pages_written/Innodb_pages_written ) = 459,782,684/523,717,889 = 87.8%- On dirait que ces valeurs devraient être égales?( Innodb_os_log_written ) = 1,071,443,919,360 / 3158494 = 339226 /sec- Ceci indique à quel point InnoDB est occupé. - InnoDB très occupé.( Innodb_log_writes ) = 110,905,716 / 3158494 = 35 /sec( Innodb_os_log_written / (Uptime / 3600) / innodb_log_files_in_group / innodb_log_file_size ) = 1,071,443,919,360 / (3158494 / 3600) / 2 / 15360M = 0.0379- Ratio - (voir minutes)( Uptime / 60 * innodb_log_file_size / Innodb_os_log_written ) = 3,158,494 / 60 * 15360M / 1071443919360 = 791- Minutes entre les rotations de journaux InnoDB À partir de 5.6.8, cela peut être modifié dynamiquement; assurez-vous également de modifier my.cnf. - (La recommandation de 60 minutes entre les rotations est quelque peu arbitraire.) Ajustez innodb_log_file_size. (Ne peut pas changer dans AWS.)( Com_rollback ) = 770,457 / 3158494 = 0.24 /sec- ROLLBACKs dans InnoDB. - Une fréquence excessive de restaurations peut indiquer une logique d'application inefficace.( Innodb_row_lock_waits ) = 632,292 / 3158494 = 0.2 /sec- Combien de fois il y a un retard dans l'obtention d'un verrou de ligne. - Peut être causé par des requêtes complexes qui pourraient être optimisées.( Innodb_dblwr_writes ) = 97,725,876 / 3158494 = 31 /sec- "Doublewrite buffer" écrit sur le disque. Les "doubles écritures" sont une fonctionnalité de fiabilité. Certaines versions / configurations plus récentes n'en ont pas besoin. - (Symptôme d'autres problèmes)( Innodb_row_lock_current_waits ) = 13- Le nombre de verrous de ligne actuellement attendus par les opérations sur les tables InnoDB. Zéro est assez normal. - Quelque chose d'important se passe?( innodb_print_all_deadlocks ) = OFF- Si vous souhaitez enregistrer tous les blocages. - Si vous êtes en proie à des blocages, activez-le. Attention: Si vous avez beaucoup de blocages, cela peut écrire beaucoup sur le disque.( local_infile ) = ON- local_infile = ON est un problème de sécurité potentiel( bulk_insert_buffer_size / _ram ) = 8M / 716800M = 0.00%- Tampon pour les INSERTs à plusieurs lignes et les données de charge - Trop gros pourrait menacer la taille de la RAM. Trop petit pourrait entraver de telles opérations.( Questions ) = 9,658,430,713 / 3158494 = 3057 /sec- Requêtes (hors SP) - "qps" -> 2000 peut stresser le serveur( Queries ) = 9,678,805,194 / 3158494 = 3064 /sec- Les requêtes (y compris à l'intérieur du SP) -> 3000 peuvent stresser le serveur( Created_tmp_tables ) = 1,107,271,497 / 3158494 = 350 /sec- Fréquence de création de tables "temporaires" dans le cadre de SELECT complexes.( Created_tmp_disk_tables ) = 297,023,373 / 3158494 = 94 /sec- Fréquence de création de tables "temp" de disque dans le cadre de SELECT complexes - augmentez tmp_table_size et max_heap_table_size. Vérifiez les règles des tables temporaires lorsque MEMORY est utilisé à la place de MyISAM. Des modifications mineures de schéma ou de requête peuvent peut-être éviter MyISAM. De meilleurs index et une reformulation des requêtes sont plus susceptibles de vous aider.( (Com_insert + Com_update + Com_delete + Com_replace) / Com_commit ) = (693300264 + 214511608 + 37537668 + 0) / 1672382928 = 0.565- Déclarations par engagement (en supposant que tous les InnoDB) - Faible: pourrait aider à regrouper les requêtes dans les transactions; Élevé: les transactions longues mettent à rude épreuve diverses choses.( Select_full_join ) = 338,957,314 / 3158494 = 107 /sec- jointures sans index - Ajoutez des index appropriés aux tables utilisées dans JOINs.( Select_full_join / Com_select ) = 338,957,314 / 6763083714 = 5.0%-% de sélections qui sont jointes sans index - Ajoutez des index appropriés aux tables utilisées dans JOINs.( Select_scan ) = 124,606,973 / 3158494 = 39 /sec- analyses de table complètes - Ajouter des index / optimiser les requêtes (sauf si ce sont de petites tables)( Sort_merge_passes ) = 1,136,548 / 3158494 = 0.36 /sec- Tri lourd - Augmentez sort_buffer_size et / ou optimisez les requêtes complexes.( Com_insert + Com_delete + Com_delete_multi + Com_replace + Com_update + Com_update_multi ) = (693300264 + 37537668 + 198418338 + 0 + 214511608 + 79274476) / 3158494 = 387 /sec- écritures / sec - 50 écritures / sec + vidages de journaux maximiseront probablement la capacité d'écriture d'E / S des disques normaux( ( Com_stmt_prepare - Com_stmt_close ) / ( Com_stmt_prepare + Com_stmt_close ) ) = ( 39 - 38 ) / ( 39 + 38 ) = 1.3%- Fermez-vous vos déclarations préparées? - Ajouter ferme.( Com_stmt_close / Com_stmt_prepare ) = 38 / 39 = 97.4%- Les déclarations préparées doivent être fermées. - Vérifiez si toutes les instructions préparées sont "fermées".( innodb_autoinc_lock_mode ) = 1- Galera: désirs 2 - 2 = "entrelacé"; 1 = "consécutif" est typique; 0 = "traditionnel".( Max_used_connections / max_connections ) = 701 / 700 = 100.1%-% de connexions de pointe - augmentez max_connections et / ou diminuez wait_timeout( Threads_running - 1 ) = 71 - 1 = 70- Threads actifs (simultané lorsque les données sont collectées) - Optimiser les requêtes et / ou le schémaAnormalement volumineux: (La plupart d'entre eux proviennent d'un système très occupé.)
(a continué)
la source
innodb_flush_log_at_trx_commit = 2ne semble pas avoir d'effet et la contention des threads ne semble pas non plus être le problème car même à des charges modérées (Threads runnig <50), l'utilisateur du système sys / CPU est quelque chose comme 3 à 1.Nous n'avons jamais compris quelle était la cause exacte de ce problème, mais pour offrir une fermeture, je vais dire ce que je peux.
Notre équipe a effectué des tests de charge et a conclu qu'il
MySQLavait des problèmes d'allocation de mémoire. Ils ont donc essayé d'utiliserjemallocau lieu deglibcet le problème a disparu. Nous utilisons lajemallocproduction depuis plus de 6 mois maintenant, sans jamais revoir ce problème.Je ne dis pas que
jemallocc'est mieux, ou que tout le monde devrait l'utiliser avecMySQL. Mais il semble que notre cas spécifiqueglibcne fonctionnait tout simplement pas correctement.la source
Mes 2 cents.
Exécutez "iostat -xk 5" pour essayer de voir si le disque pose toujours un problème. Le système CPU est également lié au code système (kernell), vérifiez le nouveau disque / pilotes / config.
la source
Suggestions pour la section my.cnf / ini [mysqld] pour votre TRÈS OCCUPÉ
Mon attente est une diminution progressive des résultats de SHOW GLOBAL STATUS LIKE 'innodb_buffer_pool_pages_dirty'; avec ces suggestions appliquées. Le 13/01/18, vous aviez plus de 4 millions de pages sales.
J'espère que ces aides. Ceux-ci peuvent être modifiés dynamiquement. Il existe de nombreuses autres opportunités, si vous les souhaitez, faites-le moi savoir.
la source
Avec IOPS à 30K testé (nous avons besoin d'un certain nombre d'IOPS pour les écritures aléatoires), considérez cette suggestion pour la section my.cnf / ini [mysqld]
peut être modifié dynamiquement avec SET GLOBAL et devrait réduire rapidement innodb_buffer_pool_pages_dirty.
La cause de COM_ROLLBACK en moyenne 1 toutes les 4 secondes restera un problème de performances jusqu'à sa résolution.
@chimmi 9 avr.2018 Procurez-vous ce script MySQL sur https://pastebin.com/aZAu2zZ0 pour une vérification rapide des ressources d'état global utilisées ou publiées pendant nn secondes que vous pouvez définir dans SLEEP. Cela vous permettra de voir si quelqu'un a contribué à réduire votre fréquence COM_ROLLBACK. J'aimerais avoir de vos nouvelles par courriel.
la source
Votre SHOW GLOBAL STATUS indique que innodb_buffer_pool_pages_dirty était de 4 291 574.
Pour surveiller le nombre actuel,
Pour encourager la réduction de ce nombre,
En une heure, exécutez la demande du moniteur pour voir où vous en êtes avec les pages sales.
Veuillez me faire part de vos chiffres au début et une heure plus tard.
Appliquez la modification à votre my.cnf pour une meilleure santé à long terme de la réduction des pages sales.
la source