Penggunaan waktu sistem CPU tinggi pada server MySQL

9

Sedikit latar belakang, beberapa waktu lalu kami mulai mengalami waktu sistem CPU yang tinggi pada salah satu database MySQL kami. Basis data ini juga menderita dari pemanfaatan disk yang tinggi sehingga kami menduga bahwa hal-hal itu terhubung. Dan karena kami sudah memiliki rencana untuk memigrasikannya ke SSD, kami pikir itu akan menyelesaikan kedua masalah.

Itu membantu ... tapi tidak lama.

Selama beberapa minggu setelah migrasi, grafik CPU seperti ini: grafik beban cpu yang baik

Tapi sekarang kita kembali ke ini: grafik beban cpu buruk

Ini terjadi entah dari mana, tanpa perubahan yang jelas dalam logika aplikasi atau beban.

Statistik DB:

  • Versi MySQL - 5.7.20
  • OS - Debian
  • Ukuran DB - 1.2Tb
  • RAM - 700Gb
  • Core CPU - 56
  • Mengintip beban - sekitar 5kq / s baca, 600q / s tulis (meskipun kueri pemilihan seringkali cukup kompleks)
  • Utas - 50 berjalan, 300 terhubung
  • Ini memiliki sekitar 300 tabel, semua InnoDB

Konfigurasi 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 

Pengamatan lainnya

perf dari proses mysql selama beban puncak:

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)                                                                                                                                       

Ini menunjukkan bahwa mysql menghabiskan banyak waktu di spin_locks . Aku berharap mendapat petunjuk dari mana kunci-kunci itu berasal, sayangnya, tidak beruntung.

Profil permintaan selama beban tinggi menunjukkan jumlah ekstrim dari sakelar konteks. Saya menggunakan pilih * dari MyTable di mana pk = 123 , MyTable memiliki sekitar 90M baris. Output 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         1902

Peter Zaitsev membuat posting baru-baru ini tentang sakelar konteks, di mana ia berkata:

Namun, di dunia nyata, saya tidak akan khawatir tentang pertikaian menjadi masalah besar jika Anda memiliki kurang dari sepuluh sakelar konteks per kueri.

Tapi itu menunjukkan lebih dari 600 sakelar!

Apa yang dapat menyebabkan gejala-gejala ini dan apa yang dapat dilakukan untuk mengatasinya? Saya akan menghargai setiap petunjuk atau info tentang masalah ini, semua yang saya temui sejauh ini agak lama dan / atau tidak meyakinkan.

PS Saya dengan senang hati akan memberikan informasi tambahan, jika diperlukan.

Output dari SHOW STATUS GLOBAL dan SHOW VARIABEL

Saya tidak dapat mempostingnya di sini karena isinya melebihi batas ukuran posting.

TAMPILKAN STATUS GLOBAL
TAMPILKAN VARIABEL

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

Pembaruan 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
sumber
Berapa lama (waktu yang berlalu) yang select * from MyTable where pk = 123dibutuhkan rata-rata?
Rick James
1
@ RickJames Dibutuhkan rata-rata sekitar 5 ms.
chimmi
1
@ WillsonHauck Tes menunjukkan sekitar 30k tulis IOps. Adapun halaman kotor, jumlah 9% yang kita miliki, sepertinya tidak masalah bagi saya. Kami menemukan bahwa setelah reboot, penggunaan CPU akan tetap normal selama sekitar satu minggu, jadi rencananya adalah menunggu untuk reboot berikutnya dan memantau global statusuntuk melihat apakah ada yang berkorelasi dengan peningkatan penggunaan CPU. Saya tidak percaya apa pun dapat dicapai dengan data yang tersedia saat ini. Saya akan mengajukan pertanyaan lain jika saya menemukan sesuatu yang baru.
chimmi
1
@ WillsonHauck Kami memiliki reboot dan berjalan seperti sebelumnya: waktu sistem mulai tumbuh. Masih mencari sumber masalah.
chimmi
1
@WilsonHauck Pertanyaan diperbarui.
chimmi

Jawaban:

6

600q / s tulis dengan flush per komit mungkin mencapai batas disk pemintalan Anda saat ini. Beralih ke SSD akan mengurangi tekanan.

Perbaikan cepat (sebelum mendapatkan SSD) mungkin untuk mengubah pengaturan ini:

innodb_flush_log_at_trx_commit = 2

Tapi baca peringatan tentang membuat perubahan itu.

Memiliki pengaturan itu dan SSD akan membuat Anda tumbuh lebih jauh.

Perbaikan lain yang mungkin adalah menggabungkan beberapa penulisan menjadi satu COMMIT(di mana logika tidak dilanggar).

Hampir selalu, CPU tinggi dan / atau I / O disebabkan oleh indeks yang buruk dan / atau formulasi pertanyaan yang buruk. Nyalakan slowlog dengan long_query_time=1, tunggu sebentar, lalu lihat apa yang muncul. Dengan pertanyaan di tangan, memberikan SELECT, EXPLAIN SELECT ...dan SHOW CREATE TABLE. Ditto untuk permintaan tulis. Dari itu, kita mungkin bisa menjinakkan CPU dan / atau I / O. Bahkan dengan pengaturan Anda saat ini 3, pt-query-digestmungkin menemukan beberapa hal menarik.

Perhatikan bahwa dengan 50 utas "berjalan", ada banyak pertengkaran; ini mungkin menyebabkan peralihan, dll, yang Anda catat. Kita perlu mendapatkan kueri untuk menyelesaikan lebih cepat. Dengan 5.7, sistem dapat terjungkal dengan 100 thread yang berjalan . Bertambah melampaui sekitar 64, konteks beralih, mutex, kunci, dll, berkonspirasi untuk memperlambat setiap utas, yang mengarah ke tidak ada peningkatan dalam throughput sementara latensi melewati atap.

Untuk pendekatan berbeda dalam menganalisis masalah, harap berikan SHOW VARIABLESdan SHOW GLOBAL STATUS? Lebih banyak diskusi di sini .

Analisis VARIABEL & STATUS

(Maaf, tidak ada yang keluar saat menjawab Pertanyaan Anda.)

Pengamatan:

  • Versi: 5.7.20-log
  • RAM 700 GB
  • Uptime = 36d 13:21:34
  • Anda tidak berjalan di Windows.
  • Menjalankan versi 64-bit
  • Anda tampaknya sepenuhnya menjalankan (atau sebagian besar) InnoDB.

Masalah yang Lebih Penting:

Banyak tabel temp, terutama berbasis disk, dibuat untuk permintaan kompleks. Mari kita berharap bahwa log lambat akan mengidentifikasi beberapa pertanyaan yang dapat diperbaiki (melalui pengindeksan / reformulasi / dll.) Indikator lainnya bergabung tanpa indeks dan sort_merge_passes; Namun, tak satu pun dari ini konklusif, kita perlu melihat pertanyaan.

Max_used_connections = 701adalah> = Max_connections = 700, jadi mungkin ada beberapa koneksi yang ditolak. Juga, jika itu mengindikasikan lebih dari, katakanlah, 64 utas berjalan , maka kinerja sistem mungkin menderita pada saat itu. Pertimbangkan pembatasan jumlah koneksi dengan pembatasan klien. Apakah Anda menggunakan Apache, Tomcat, atau yang lainnya? 70 Threads_runningmenunjukkan bahwa, pada saat melakukan ini SHOW, sistem sedang dalam masalah.

Meningkatkan jumlah pernyataan di setiap COMMIT(bila masuk akal) dapat membantu kinerja beberapa.

innodb_log_file_size, pada 15GB, lebih besar dari yang diperlukan, tapi saya melihat tidak perlu mengubahnya.

Ribuan meja biasanya bukan desain yang bagus.

eq_range_index_dive_limit = 200perhatian saya, tapi saya tidak tahu bagaimana memberi saran. Apakah itu pilihan yang disengaja?

Mengapa begitu banyak PROSEDUR CREATE + DROP?

Mengapa banyak perintah SHOW?

Detail dan pengamatan lainnya:

( Innodb_buffer_pool_pages_flushed ) = 523,716,598 / 3158494 = 165 /sec - Menulis (flushes) - periksa innodb_buffer_pool_size

( table_open_cache ) = 10,000 - Jumlah deskriptor tabel untuk cache - Beberapa ratus biasanya baik.

( (Innodb_buffer_pool_reads + Innodb_buffer_pool_pages_flushed) ) = ((61,040,718 + 523,716,598) ) / 3158494 = 185 /sec - InnoDB I / O

( Innodb_dblwr_pages_written/Innodb_pages_written ) = 459,782,684/523,717,889 = 87.8% - Sepertinya nilai-nilai ini harus sama?

( Innodb_os_log_written ) = 1,071,443,919,360 / 3158494 = 339226 /sec- Ini adalah indikator seberapa sibuk InnoDB. - InnoDB sangat sibuk.

( 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 - Rasio - (lihat menit)

( Uptime / 60 * innodb_log_file_size / Innodb_os_log_written ) = 3,158,494 / 60 * 15360M / 1071443919360 = 791- Menit antara rotasi log InnoDB Dimulai dengan 5.6.8, ini dapat diubah secara dinamis; pastikan juga untuk mengubah my.cnf. - (Rekomendasi 60 menit antara rotasi agak sewenang-wenang.) Sesuaikan innodb_log_file_size. (Tidak dapat mengubah AWS.)

( Com_rollback ) = 770,457 / 3158494 = 0.24 /sec- ROLLBACKs dalam InnoDB. - Frekuensi pengembalian yang berlebihan dapat menunjukkan logika aplikasi yang tidak efisien.

( Innodb_row_lock_waits ) = 632,292 / 3158494 = 0.2 /sec- Seberapa sering ada keterlambatan dalam mendapatkan kunci baris. - Mungkin disebabkan oleh pertanyaan kompleks yang dapat dioptimalkan.

( Innodb_dblwr_writes ) = 97,725,876 / 3158494 = 31 /sec- "Doublewrite buffer" menulis ke disk. "Doublewrites" adalah fitur keandalan. Beberapa versi / konfigurasi yang lebih baru tidak membutuhkannya. - (Gejala masalah lain)

( Innodb_row_lock_current_waits ) = 13- Jumlah kunci baris saat ini sedang ditunggu oleh operasi pada tabel InnoDB. Nol cukup normal. - Sesuatu yang besar sedang terjadi?

( innodb_print_all_deadlocks ) = OFF- Apakah akan mencatat semua Deadlock. - Jika Anda diganggu dengan Deadlock, hidupkan ini. Perhatian: Jika Anda memiliki banyak deadlock, ini mungkin menulis banyak ke disk.

( local_infile ) = ON - local_infile = ON adalah masalah keamanan potensial

( bulk_insert_buffer_size / _ram ) = 8M / 716800M = 0.00%- Buffer untuk INSERT multi-baris dan DATA LOAD - Terlalu besar dapat mengancam ukuran RAM. Terlalu kecil dapat menghambat operasi semacam itu.

( Questions ) = 9,658,430,713 / 3158494 = 3057 /sec- Permintaan (di luar SP) - "qps" -> 2000 mungkin menekankan server

( Queries ) = 9,678,805,194 / 3158494 = 3064 /sec- Permintaan (termasuk di dalam SP) -> 3000 mungkin menekankan server

( Created_tmp_tables ) = 1,107,271,497 / 3158494 = 350 /sec - Frekuensi membuat tabel "temp" sebagai bagian dari SELECT yang kompleks.

( Created_tmp_disk_tables ) = 297,023,373 / 3158494 = 94 /sec- Frekuensi membuat tabel disk "temp" sebagai bagian dari SELECT yang kompleks - tingkatkan tmp_table_size dan max_heap_table_size. Periksa aturan untuk tabel temp pada saat MEMORY digunakan sebagai ganti MyISAM. Mungkin perubahan skema atau permintaan kecil dapat menghindari MyISAM. Indeks yang lebih baik dan formulasi ulang pertanyaan lebih mungkin untuk membantu.

( (Com_insert + Com_update + Com_delete + Com_replace) / Com_commit ) = (693300264 + 214511608 + 37537668 + 0) / 1672382928 = 0.565- Pernyataan per Komit (dengan asumsi semua InnoDB) - Rendah: Mungkin membantu untuk mengelompokkan pertanyaan dalam transaksi; Tinggi: transaksi jangka panjang memecah berbagai hal.

( Select_full_join ) = 338,957,314 / 3158494 = 107 /sec - bergabung tanpa indeks - Tambahkan indeks yang sesuai ke tabel yang digunakan dalam GABUNG.

( Select_full_join / Com_select ) = 338,957,314 / 6763083714 = 5.0% -% dari pilihan yang tidak bergabung dengan indeks - Tambahkan indeks yang sesuai ke tabel yang digunakan dalam GABUNG.

( Select_scan ) = 124,606,973 / 3158494 = 39 /sec - pemindaian tabel penuh - Tambahkan indeks / optimalkan kueri (kecuali jika itu adalah tabel kecil)

( Sort_merge_passes ) = 1,136,548 / 3158494 = 0.36 /sec - Jenis Heafty - Tingkatkan sort_buffer_size dan / atau optimalkan permintaan kompleks.

( Com_insert + Com_delete + Com_delete_multi + Com_replace + Com_update + Com_update_multi ) = (693300264 + 37537668 + 198418338 + 0 + 214511608 + 79274476) / 3158494 = 387 /sec - write / sec - 50 write / sec + log flushes mungkin akan memaksimalkan kapasitas penulisan I / O drive normal

( ( Com_stmt_prepare - Com_stmt_close ) / ( Com_stmt_prepare + Com_stmt_close ) ) = ( 39 - 38 ) / ( 39 + 38 ) = 1.3%- Apakah Anda menutup pernyataan yang sudah disiapkan? - Tambahkan Penutupan.

( Com_stmt_close / Com_stmt_prepare ) = 38 / 39 = 97.4%- Pernyataan yang disiapkan harus Ditutup. - Periksa apakah semua pernyataan yang disiapkan "Ditutup".

( innodb_autoinc_lock_mode ) = 1- Galera: keinginan 2 - 2 = "disisipkan"; 1 = "berturut-turut" adalah tipikal; 0 = "tradisional".

( Max_used_connections / max_connections ) = 701 / 700 = 100.1% - Peak% of koneksi - meningkatkan max_connections dan / atau mengurangi wait_timeout

( Threads_running - 1 ) = 71 - 1 = 70 - Utas aktif (konkurensi saat data dikumpulkan) - Optimalkan kueri dan / atau skema

Besar abnormal: (Sebagian besar berasal dari sistem yang sangat sibuk.)

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

(lanjutan)

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
sumber
1
Ya terima kasih, saya menghargai pekerjaan Anda. Sayangnya, saya tidak melihat apa pun yang dapat menjelaskan perubahan tiba-tiba kami dalam penggunaan CPU (yang pada dasarnya terjadi dalam semalam tanpa perubahan nyata pada ukuran atau beban DB atau aplikasi). innodb_flush_log_at_trx_commit = 2tampaknya tidak memiliki efek dan pertikaian utas juga tampaknya tidak menjadi masalah karena bahkan pada beban moderat (Thread runnig <50) CPU sys / pengguna CPU adalah sekitar 3 hingga 1.
chimmi
4

Kami tidak pernah menemukan apa penyebab sebenarnya dari masalah ini, tetapi untuk menawarkan beberapa penutupan saya akan mengatakan apa yang saya bisa.

Tim kami melakukan beberapa tes beban dan menyimpulkan bahwa MySQLada masalah dalam mengalokasikan memori. Jadi mereka mencoba menggunakan jemallocalih-alih glibcdan masalahnya hilang. Kami telah menggunakan jemallocdalam produksi lebih dari 6 bulan sekarang, tanpa pernah melihat masalah ini lagi.

Saya tidak mengatakan itu jemalloclebih baik, atau semua orang harus menggunakannya MySQL. Tapi sepertinya untuk kasus khusus kami glibctidak berfungsi dengan baik.

chimmi
sumber
2

2 sen saya.

Jalankan "iostat -xk 5" untuk mencoba melihat apakah disk masih bermasalah. Juga sistem CPU terkait dengan kode sistem (kernel), periksa kembali disk / driver / config baru.

andres
sumber
1
iostat tidak menunjukkan angka besar.
chimmi
ya saya bisa melihat iostat di atas tetapi angka yang dipindahkan tidak cocok dengan grafik. Apakah Anda menjalankan iostat pada jangka waktu yang sama?
andres
1
Lebih atau kurang, kami membuat beberapa perubahan pada aplikasi ke jumlah kueri yang lebih rendah yang mencapai DB ini, sehingga CPU tidak menempel pada 100% tidak lebih. Saya telah memasang output iostat lainnya, saat ini rata-rata CPU pada 75%, sistem 60%.
chimmi
0

Saran untuk bagian my.cnf / ini [mysqld] untuk SANGAT SIBUK

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

Harapan saya adalah penurunan bertahap pada SHOW STATUS GLOBAL SEPERTI 'innodb_buffer_pool_pages_dirty'; dengan saran ini diterapkan. Pada 1/13/18 Anda memiliki lebih dari 4 juta halaman kotor.

Saya harap ini membantu. Ini dapat dimodifikasi secara dinamis. Ada lebih banyak peluang, jika Anda menginginkannya, beri tahu saya.

Wilson Hauck
sumber
Terima kasih atas saran Anda, tetapi masalah ini sudah dipecahkan sejak lama. Lihat jawaban saya untuk detailnya.
chimmi
0

Dengan IOPS pada 30K diuji (kami membutuhkan sejumlah IOPS untuk Penulisan Acak), pertimbangkan Saran ini untuk bagian 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

dapat diubah secara dinamis dengan SET GLOBAL dan harus mengurangi innodb_buffer_pool_pages_dirty dengan cepat.

Penyebab COM_ROLLBACK rata-rata 1 setiap 4 detik akan tetap menjadi masalah kinerja hingga diselesaikan.

@chimmi 9 Apr 2018 Ambil skrip MySQL ini dari https://pastebin.com/aZAu2zZ0 untuk pemeriksaan cepat pada sumber daya Status Global yang digunakan atau dirilis selama beberapa detik yang dapat Anda atur dalam SLEEP. Ini memungkinkan Anda melihat apakah ada yang membantu mengurangi frekuensi COM_ROLLBACK Anda. Ingin mendengar dari Anda melalui email.

Wilson Hauck
sumber
@chimmi Silakan mulai Pertanyaan baru dengan permintaan informasi tambahan. Posting di pastebin.com atau di sini. lengkap (tidak diedit) my.cnf-ini Teks hasil dari: A) SHOW STATUS GLOBAL; B) MENUNJUKKAN VARIABEL GLOBAL; C) lengkapi laporan MySQLTuner.com jika tersedia - 7 hari atau lebih uptime sangat membantu D) MENUNJUKKAN STATUS ENGINE INNODB; Informasi opsional yang sangat membantu, jika tersedia meliputi - htop ATAU top untuk sebagian besar aplikasi yang aktif, ulimit -a untuk daftar batas, df -j untuk daftar ruang kosong berdasarkan perangkat, gratis -m untuk linux / unix memori gratis untuk server saat ini analisis.
Wilson Hauck
@ chimmi Juga, silakan kirim cat / proc / meminfo untuk jumlah saklar konteks. Tolong beri tahu saya tautan untuk pertanyaan baru. Terima kasih
Wilson Hauck
0

SHOW STATUS GLOBAL Anda menunjukkan innodb_buffer_pool_pages_dirty adalah 4.291.574.

Untuk memantau jumlah saat ini,

SHOW GLOBAL STATUS LIKE '%pages_dirty';

Untuk mendorong pengurangan jumlah ini,

SET GLOBAL innodb_flushing_avg_loops=5;

Dalam satu jam jalankan permintaan monitor untuk melihat di mana Anda berdiri dengan halaman kotor.

Tolong beri tahu saya hitungan Anda di awal dan satu jam kemudian.

Terapkan perubahan pada my.cnf Anda untuk kesehatan jangka panjang yang lebih baik dari pengurangan kotor.

Wilson Hauck
sumber
@chimmi Terima kasih telah berbagi resolusi utama jemalloc. Proses pemantauan untuk pages_dirty ini dapat membantu lingkungan produksi Anda. Tolong, coba dan bagikan nomor Anda dengan saya. Terima kasih
Wilson Hauck