Alto uso de tempo do sistema da CPU no servidor MySQL

9

Um pouco atrás, há algum tempo, começamos a experimentar um alto tempo de sistema da CPU em um de nossos bancos de dados MySQL. Esse banco de dados também estava sofrendo com a alta utilização do disco, então concluímos que essas coisas estão conectadas. E como já tínhamos planos de migrá-lo para o SSD, pensamos que ele resolveria os dois problemas.

Ajudou ... mas não por muito tempo.

Por algumas semanas após a migração, o gráfico da CPU ficou assim: bom gráfico de carga da CPU

Mas agora voltamos a isso: gráfico de carga ruim da CPU

Isso aconteceu do nada, sem alterações aparentes na carga ou na lógica do aplicativo.

Estatísticas do banco de dados:

  • Versão MySQL - 5.7.20
  • OS - Debian
  • Tamanho do DB - 1.2Tb
  • RAM - 700Gb
  • Núcleos da CPU - 56
  • Peek load - cerca de 5kq / s de leitura, gravação de 600q / s (embora as consultas selecionadas geralmente sejam bastante complexas)
  • Linhas - 50 em execução, 300 conectadas
  • Possui cerca de 300 tabelas, todas InnoDB

Configuração do 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 

Outras observações

perf do processo mysql durante o pico de carregamento:

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)                                                                                                                                       

Isso mostra que o mysql está gastando muito tempo em spin_locks . Eu esperava ter alguma pista de onde estão vindo esses bloqueios, infelizmente, sem sorte.

O perfil de consulta durante alta carga mostra uma quantidade extrema de opções de contexto. Eu usei select * from MyTable, onde pk = 123 , MyTable tem cerca de 90 milhões de linhas. Saída do perfil:

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         1902

Peter Zaitsev fez um post recentemente sobre as alternâncias de contexto, onde diz:

No mundo real, porém, eu não me preocuparia se a contenção fosse um grande problema se você tiver menos de dez alternâncias de contexto por consulta.

Mas mostra mais de 600 switches!

O que pode causar esses sintomas e o que pode ser feito sobre isso? Eu aprecio qualquer indicação ou informação sobre o assunto, tudo o que me deparei até agora é bastante antigo e / ou inconclusivo.

PS Terei prazer em fornecer informações adicionais, se necessário.

Saída de SHOW STATUS GLOBAL e SHOW VARIABLES

Não posso publicá-lo aqui porque o conteúdo excede o limite de tamanho da postagem.

MOSTRAR STATUS GLOBAIS
MOSTRAR VARIÁVEIS

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,56

Atualização 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
chimmi
fonte
Quanto tempo (tempo decorrido) select * from MyTable where pk = 123leva em média?
Rick James
11
@ RickJames Demora cerca de 5ms em média.
Chimmi
11
Os testes do @WilsonHauck mostram cerca de 30 mil IOps de gravação. Quanto às páginas sujas, a quantidade de 9% que temos, não me parece um problema. Descobrimos que, após a reinicialização, o uso da CPU permanece normal por cerca de uma semana; portanto, o plano é aguardar a próxima reinicialização e monitorar global statuspara ver se há algo relacionado ao aumento do uso da CPU. Não acredito que nada possa ser alcançado com os dados disponíveis no momento. Farei outra pergunta se encontrar algo novo.
Chimmi
11
@WilsonHauck Tivemos uma reinicialização e foi como antes: a hora do sistema começou a crescer. Ainda procurando a fonte do problema.
Chimmi 13/03/19
11
@WilsonHauck Pergunta atualizada.
Chimmi

Respostas:

6

A gravação de 600q / s com um flush por confirmação provavelmente está atingindo o limite dos discos giratórios atuais. Mudar para SSDs aliviaria a pressão.

A solução rápida (antes de obter SSDs) provavelmente deve ser alterada para esta configuração:

innodb_flush_log_at_trx_commit = 2

Mas leia as advertências sobre como fazer essa alteração.

Ter essa configuração e SSDs permitiria que você crescesse ainda mais.

Outra correção possível é combinar algumas gravações em uma única COMMIT(onde a lógica não é violada).

Quase sempre, a alta CPU e / ou E / S se deve a índices inadequados e / ou formulação deficiente de consultas. Ative o slowlog com long_query_time=1, aguarde um pouco e veja o que aparece. Com consultas na mão, fornecer SELECT, EXPLAIN SELECT ...e SHOW CREATE TABLE. O mesmo vale para as consultas de gravação. Desses, provavelmente podemos domar a CPU e / ou E / S. Mesmo com sua configuração atual de 3, pt-query-digestpode encontrar algumas coisas interessantes.

Observe que, com 50 threads "em execução", há muita disputa; isso pode estar causando a troca, etc., que você anotou. Precisamos que as consultas terminem mais rapidamente. Com o 5.7, o sistema pode tombar com 100 threads em execução . Indo além de cerca de 64, as alternâncias de contexto, mutexes, bloqueios etc. conspiram para diminuir a velocidade de cada encadeamento, levando a nenhuma melhoria na taxa de transferência enquanto a latência passa pelo teto.

Para uma abordagem diferente para analisar o problema, forneça SHOW VARIABLESe SHOW GLOBAL STATUS? Mais discussão aqui .

Análise de VARIÁVEIS E ESTADO

(Desculpe, nada salta como resposta à sua pergunta.)

Observações:

  • Versão: 5.7.20-log
  • 700 GB de RAM
  • Tempo de atividade = 36d 13:21:34
  • Você não está executando no Windows.
  • Executando a versão de 64 bits
  • Você parece estar executando inteiramente (ou principalmente) o InnoDB.

As questões mais importantes:

Muitas tabelas temporárias, especialmente baseadas em disco, são criadas para consultas complexas. Vamos esperar que o log lento identifique algumas consultas que podem ser aprimoradas (via indexação / reformulação / etc.) Outros indicadores são junções sem índices e sort_merge_passes; no entanto, nenhuma dessas é conclusiva, precisamos ver as consultas.

Max_used_connections = 701é> = Max_connections = 700, portanto, provavelmente houve algumas conexões recusadas. Além disso, se isso indicou mais de, digamos, 64 threads em execução , o desempenho do sistema provavelmente sofreu naquele momento. Considere limitar o número de conexões ao limitar os clientes. Você está usando Apache, Tomcat ou algo mais? 70 Threads_runningindica que, no momento de fazer isso SHOW, o sistema estava com problemas.

Aumentar o número de declarações em cada uma COMMIT(quando razoável) pode ajudar no desempenho de algumas.

innodb_log_file_size, com 15 GB, é maior que o necessário, mas não vejo a necessidade de alterá-lo.

Milhares de tabelas geralmente não são um bom design.

eq_range_index_dive_limit = 200me preocupa, mas não sei como aconselhar. Foi uma escolha deliberada?

Por que tantos CREATE + DROP PROCEDURE?

Por que tantos comandos SHOW?

Detalhes e outras observações:

( Innodb_buffer_pool_pages_flushed ) = 523,716,598 / 3158494 = 165 /sec - Grava (flushes) - verifique innodb_buffer_pool_size

( table_open_cache ) = 10,000 - Número de descritores de tabela para armazenar em cache - Várias centenas geralmente são boas.

( (Innodb_buffer_pool_reads + Innodb_buffer_pool_pages_flushed) ) = ((61,040,718 + 523,716,598) ) / 3158494 = 185 /sec - E / S do InnoDB

( Innodb_dblwr_pages_written/Innodb_pages_written ) = 459,782,684/523,717,889 = 87.8% - Parece que esses valores devem ser iguais?

( Innodb_os_log_written ) = 1,071,443,919,360 / 3158494 = 339226 /sec- Este é um indicador de quão ocupado o InnoDB está. - InnoDB muito ocupado.

( 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 - Proporção - (ver minutos)

( Uptime / 60 * innodb_log_file_size / Innodb_os_log_written ) = 3,158,494 / 60 * 15360M / 1071443919360 = 791- Minutos entre as rotações do log do InnoDB A partir da versão 5.6.8, isso pode ser alterado dinamicamente; não se esqueça de alterar também my.cnf. - (A recomendação de 60 minutos entre as rotações é um tanto arbitrária.) Ajuste innodb_log_file_size. (Não é possível alterar na AWS.)

( Com_rollback ) = 770,457 / 3158494 = 0.24 /sec- ROLLBACKs no InnoDB. - Uma frequência excessiva de reversões pode indicar lógica ineficiente do aplicativo.

( Innodb_row_lock_waits ) = 632,292 / 3158494 = 0.2 /sec- Com que frequência há um atraso na obtenção de um bloqueio de linha. - Pode ser causado por consultas complexas que podem ser otimizadas.

( Innodb_dblwr_writes ) = 97,725,876 / 3158494 = 31 /sec- "Buffer de gravação dupla" grava no disco. "Doublewrites" são um recurso de confiabilidade. Algumas versões / configurações mais recentes não precisam delas. - (sintoma de outras questões)

( Innodb_row_lock_current_waits ) = 13- O número de bloqueios de linha atualmente sendo aguardados pelas operações nas tabelas do InnoDB. Zero é bem normal. - Algo grande está acontecendo?

( innodb_print_all_deadlocks ) = OFF- Se deve registrar todos os deadlocks. - Se você estiver atormentado com deadlocks, ative-o. Cuidado: Se você tiver muitos deadlocks, isso pode gravar muito no disco.

( local_infile ) = ON - local_infile = ON é um possível problema de segurança

( bulk_insert_buffer_size / _ram ) = 8M / 716800M = 0.00%- Buffer para INSERTs com várias linhas e LOAD DATA - Muito grande pode ameaçar o tamanho da RAM. Um tamanho muito pequeno pode dificultar essas operações.

( Questions ) = 9,658,430,713 / 3158494 = 3057 /sec- Consultas (fora de SP) - "qps" -> 2000 podem estar estressando o servidor

( Queries ) = 9,678,805,194 / 3158494 = 3064 /sec- Consultas (inclusive dentro de SP) -> 3000 podem estar estressando o servidor

( Created_tmp_tables ) = 1,107,271,497 / 3158494 = 350 /sec - Frequência de criação de tabelas "temporárias" como parte de SELECTs complexos.

( Created_tmp_disk_tables ) = 297,023,373 / 3158494 = 94 /sec- Frequência de criação de tabelas "temporárias" de disco como parte de SELECTs complexos - aumente tmp_table_size e max_heap_table_size. Verifique as regras para as tabelas temporárias quando o MEMORY for usado, em vez do MyISAM. Talvez pequenas alterações no esquema ou na consulta possam evitar o MyISAM. Melhores índices e reformulação de consultas são mais propensos a ajudar.

( (Com_insert + Com_update + Com_delete + Com_replace) / Com_commit ) = (693300264 + 214511608 + 37537668 + 0) / 1672382928 = 0.565- Declarações por confirmação (assumindo todo o InnoDB) - Baixa: Pode ajudar a agrupar consultas em transações; Alto: transações longas sobrecarregam várias coisas.

( Select_full_join ) = 338,957,314 / 3158494 = 107 /sec - junções sem índice - Adicione índices adequados às tabelas usadas em JOINs.

( Select_full_join / Com_select ) = 338,957,314 / 6763083714 = 5.0% -% de seleções que são junção sem índice - Adicione índices adequados às tabelas usadas em JOINs.

( Select_scan ) = 124,606,973 / 3158494 = 39 /sec - varreduras completas de tabelas - Adicione índices / otimize consultas (a menos que sejam pequenas tabelas)

( Sort_merge_passes ) = 1,136,548 / 3158494 = 0.36 /sec - Classificação de Heafty - Aumente sort_buffer_size e / ou otimize consultas complexas.

( Com_insert + Com_delete + Com_delete_multi + Com_replace + Com_update + Com_update_multi ) = (693300264 + 37537668 + 198418338 + 0 + 214511608 + 79274476) / 3158494 = 387 /sec - gravações / s - 50 gravações / s + descargas de log provavelmente maximizarão a capacidade de gravação de E / S das unidades normais

( ( Com_stmt_prepare - Com_stmt_close ) / ( Com_stmt_prepare + Com_stmt_close ) ) = ( 39 - 38 ) / ( 39 + 38 ) = 1.3%- Você está fechando suas declarações preparadas? - Adicionar fecha.

( Com_stmt_close / Com_stmt_prepare ) = 38 / 39 = 97.4%- As declarações preparadas devem ser fechadas. - Verifique se todas as instruções preparadas estão "fechadas".

( innodb_autoinc_lock_mode ) = 1- Galera: desejos 2 - 2 = "intercalados"; 1 = "consecutivo" é típico; 0 = "tradicional".

( Max_used_connections / max_connections ) = 701 / 700 = 100.1% -% de pico de conexões - aumente max_connections e / ou diminua wait_timeout

( Threads_running - 1 ) = 71 - 1 = 70 - Threads ativos (simultaneidade quando os dados são coletados) - Otimize consultas e / ou esquema

Anormalmente grande: (A maioria deles resulta de ser um sistema muito ocupado.)

Com_commit = 529 /sec
Com_create_procedure = 0.01 /HR
Com_drop_procedure = 0.01 /HR
Com_delete = 12 /sec
Com_delete_multi = 63 /sec
Com_insert = 219 /sec
Com_kill = 0.69 /HR
Com_reset = 0.0011 /HR
Com_revoke = 0.0023 /HR
Com_select = 2141 /sec
Com_show_binlogs = 12 /HR
Com_show_create_func = 0.011 /HR
Com_show_privileges = 0.0034 /HR
Com_show_profile = 0.027 /HR
Com_show_profiles = 0.028 /HR
Com_show_slave_status = 0.037 /sec
Com_show_storage_engines = 12 /HR
Com_show_warnings = 0.14 /sec
Com_slave_stop = 0.0011 /HR
Com_update_multi = 25 /sec
Created_tmp_files = 0.3 /sec
Handler_commit = 3251 /sec
Handler_external_lock = 18787 /sec
Handler_prepare = 615 /sec
Handler_read_first = 239 /sec
Handler_read_key = 173669 /sec
Handler_read_next = 1291439 /sec
Handler_read_prev = 28535 /sec
Handler_read_rnd = 32789 /sec

(contínuo)

Innodb_buffer_pool_bytes_dirty = 7.03e+10
Innodb_buffer_pool_pages_data = 3.41e+7
Innodb_buffer_pool_pages_dirty = 4.29e+6
Innodb_buffer_pool_pages_misc = 2.15e+6
Innodb_buffer_pool_pages_total = 3.62e+7
Innodb_data_fsyncs = 132 /sec
Innodb_data_writes = 232 /sec
Innodb_data_written = 5440151 /sec
Innodb_dblwr_pages_written = 145 /sec
Innodb_os_log_written / (Uptime / 3600) / innodb_log_files_in_group = 582.3MB
Innodb_pages_written = 165 /sec
Innodb_row_lock_time = 5.97e+7
Innodb_rows_deleted + Innodb_rows_inserted = 2180 /sec
Innodb_rows_inserted = 2155 /sec
Innodb_rows_read = 1398531 /sec
Max_used_connections = 701
Open_tables = 10,000
Select_full_range_join = 2.57e+7
Select_range = 130 /sec
Sort_range = 30 /sec
Sort_scan = 332 /sec
Table_open_cache_hits = 9354 /sec
Threads_running = 71
eq_range_index_dive_limit = 200
innodb_purge_threads = 4
innodb_thread_sleep_delay = 16,925
Rick James
fonte
11
Sim, obrigado, agradeço o seu trabalho. Infelizmente, não vejo nada que possa explicar nossa mudança repentina no uso da CPU (que aconteceu basicamente da noite para o dia sem alterações aparentes no tamanho do banco de dados, na carga ou no aplicativo). innodb_flush_log_at_trx_commit = 2parece não ter nenhum efeito e a contenção de encadeamentos também não parece ser o problema, porque mesmo com cargas moderadas (Threads runnig <50) sys / usuário da CPU é algo entre 3 e 1.
chimmi
4

Nunca descobrimos qual era a causa exata desse problema, mas, para oferecer um fechamento, vou contar o que posso.

Nossa equipe fez alguns testes de carga e concluiu que MySQLhavia problemas ao alocar memória. Então eles tentaram usar em jemallocvez de glibce o problema desapareceu. Estamos usando a jemallocprodução há mais de 6 meses, sem nunca mais ver esse problema.

Não estou dizendo que jemallocé melhor ou que todos deveriam usá-lo MySQL. Mas parece que, no nosso caso específico, glibcnão estava funcionando corretamente.

chimmi
fonte
2

Meus 2 centavos.

Execute "iostat -xk 5" para tentar ver se o disco ainda está com problema. Além disso, o sistema da CPU está relacionado ao código do sistema (kernell), verifique novamente o novo disco / drivers / config.

andres
fonte
11
O iostat não mostra grandes números.
Chimmi
Sim, eu posso ver o iostat acima, mas os números exibidos não correspondem ao gráfico. Você executou o iostat no mesmo período de tempo?
andres
11
Mais ou menos, fizemos algumas alterações no aplicativo para diminuir o número de consultas que atingem esse banco de dados, para que a CPU não fique mais 100%. Anexei outra saída de iostat, no momento a CPU média estava em 75%, 60% do sistema.
Chimmi
0

Sugestões para a seção my.cnf / ini [mysqld] para o seu MUITO OCUPADO

max_heap_table_size=128M  # from 16M to match tmp_table_size
innodb_lru_scan_depth=100  # from 256 to reduce depth every second
innodb_change_buffer_max_size=15  # from 25 max used misc is 6%
innodb_flush_neighbors=0  # from 1 with SSD there is no rotational delay
innodb_read_ahead_threshold=8  # from 56 to expedite RD nxt extent
read_rnd_buffer_size=128K  # from 256K to reduce RD RPS

Minha expectativa é uma diminuição gradual nos resultados de SHOW GLOBAL STATUS LIKE 'innodb_buffer_pool_pages_dirty'; com essas sugestões aplicadas. Em 13/1/18, você tinha mais de 4 milhões de páginas sujas.

Espero que estas ajudem. Estes podem ser modificados dinamicamente. Existem muitas outras oportunidades, se você as quiser, me avise.

Wilson Hauck
fonte
Obrigado por suas sugestões, mas esse problema foi resolvido há muito tempo. Veja minha resposta para detalhes.
Chimmi
0

Com o IOPS em 30K testado (precisamos de vários IOPS para gravações aleatórias), considere esta sugestão para a seção my.cnf / ini [mysqld]

innodb_io_capacity_max=20000  # from 2000 and keep top 10000 free for now
innodb_io_capacity=10000  # from 200 to ensure we stay away from the limits

pode ser alterado dinamicamente com SET GLOBAL e deve reduzir o innodb_buffer_pool_pages_dirty rapidamente.

A causa da média de COM_ROLLBACK 1 a cada 4 segundos continuará sendo um problema de desempenho até que seja resolvido.

@chimmi 9 de abril de 2018 Pegue esse script do MySQL em https://pastebin.com/aZAu2zZ0 para uma verificação rápida dos recursos de Status Global usados ​​ou liberados por nn segundos que você pode configurar no SLEEP. Isso permitirá que você veja se alguém ajudou a reduzir sua frequência COM_ROLLBACK. Gostaria de ouvir você por e-mail.

Wilson Hauck
fonte
@chimmi Inicie uma nova pergunta com solicitação de informações adicionais, por favor. Poste em pastebin.com ou aqui. completo (não editado) my.cnf-ini Resultados de texto de: A) MOSTRA ESTADO GLOBAL; B) MOSTRAR VARIÁVEIS GLOBAIS; C) preencha o relatório do MySQLTuner.com se estiver prontamente disponível - 7 ou mais dias de atividade útil D) MOSTRE O ESTADO DO MOTOR INNODB; Informações muito úteis opcionais, se disponíveis incluem - htop OR top para aplicativos mais ativos, ulimit -a para uma lista de limites, df -h para uma lista de espaço livre por dispositivo, free -m para uma memória livre linux / unix para o servidor atual análise.
Wilson Hauck
@chimmi Além disso, poste cat / proc / meminfo para a contagem de alternância de contexto. Deixe-me saber o link para a nova pergunta, por favor. Obrigado
Wilson Hauck
0

Seu SHOW GLOBAL STATUS indica que innodb_buffer_pool_pages_dirty foram 4.291.574.

Para monitorar a contagem atual,

SHOW GLOBAL STATUS LIKE '%pages_dirty';

Para incentivar a redução dessa contagem,

SET GLOBAL innodb_flushing_avg_loops=5;

Em uma hora, execute a solicitação do monitor para ver onde você está com as páginas sujas.

Por favor, deixe-me saber suas contagens no início e uma hora depois.

Aplique a alteração no seu my.cnf para obter uma melhor saúde a longo prazo das reduções sujas de páginas.

Wilson Hauck
fonte
@chimmi Obrigado por compartilhar a resolução principal do jemalloc. Esse processo de monitoramento para pages_dirty pode ser útil para o seu ambiente de produção. Por favor, tente e compartilhe seus números comigo. Graças
Wilson Hauck