heavy read workload with high cpu usage
Posted by:
kim alex
Date: May 28, 2015 04:37AM
hi,all:
ONE of my MYSQL with high cpu usage ,i can not say any problem,hope expert can help me find the reasion!
here is my configuration
[mysqld]
datadir=/var/lib/mysql
socket=/var/lib/mysql/mysql.sock
symbolic-links=0
user=mysql
character_set_server=gbk
event_scheduler=on
key_buffer_size=60M
max_allowed_packet = 64M
max_connections = 1500
table_open_cache = 1024
thread_cache_size = 64
query_cache_size = 60M
innodb_buffer_pool_size = 48G
log-slow-queries = /tmp/slow.log
long_query_time = 0.05
skip-name-resolve
;plugin-load=rpl_semi_sync_master=semisync_master.so
;plugin-load=rpl_semi_sync_slave=semisync_slave.so
;rpl_semi_sync_master_enabled=1
;rpl_semi_sync_master_timeout=10
;rpl_semi_sync_slave_enabled=1
;performance_schema
server-id = 1
log_bin = /var/log/mysql/mysql-bin.log
read-only =0
binlog-do-db =website
binlog_format = MIXED
innodb_flush_log_at_trx_commit=2
sync_binlog=1000
open_files_limit = 65535
innodb_file_per_table
expire_logs_days=15
innodb_log_file_size=100M
innodb_log_buffer_size=50M
innodb_flush_method=O_DIRECT
innodb_thread_concurrency=16
log_queries_not_using_indexes=1
tmp_table_size=300M
max_heap_table_size=300M
[mysqld_safe]
log-error=/var/log/mysqld.log
pid-file=/var/run/mysqld/mysqld.pid
default-character-set=gbk
[mysql]
default-character-set=gbk
[client]
default-character-set=gbk
and here is my pt-digest-query output summary
# 71.7s user time, 490ms system time, 37.47M rss, 213.22M vsz
# Current date: Thu May 28 17:00:00 2015
# Hostname: dianwoba-020
# Files: slow.log
# Overall: 224.80k total, 361 unique, 12.57 QPS, 0.15x concurrency _______
# Time range: 2015-05-28 12:00:00 to 16:57:59
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 2628s 66us 2s 12ms 91ms 34ms 725us
# Lock time 49s 0 51ms 220us 214us 2ms 89us
# Rows sent 907.19k 0 3.17k 4.13 15.25 14.62 0.99
# Rows examine 559.62M 0 1.89M 2.55k 10.29k 15.65k 92.72
# Query size 62.35M 6 5.91k 290.83 719.66 389.49 258.32
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ================== ============== ====== ====== ===== =============
# 1 0x63B5CA94B72FAFF3 864.7902 32.9% 8265 0.1046 0.00 SELECT w_coupon_use_record w_coupon_user g_order_his
# 2 0x813031B8BBC3B329 472.2779 18.0% 5930 0.0796 0.02 COMMIT
# 3 0x73A8AECE3223C8C9 184.7434 7.0% 2176 0.0849 0.03 SELECT g_order g_staff
# 4 0x75B0B230FBC595D2 135.9799 5.2% 1372 0.0991 0.00 SELECT g_order_detail g_order
# 5 0x72A115F990FE72AA 66.3640 2.5% 162 0.4097 0.13 SELECT g_order wm_supplier g_order wm_supplier
# 6 0x650025804E9AD82D 43.4672 1.7% 7389 0.0059 0.00 SELECT wm_images_sup
# 7 0x1C6C2DE88CB8C7DD 40.5342 1.5% 6343 0.0064 0.01 SELECT UNION g_order g_order_his
# 8 0x66A3481D1D144586 39.3756 1.5% 291 0.1353 0.09 SELECT g_order
# 9 0x376CF737457144F8 37.8952 1.4% 6322 0.0060 0.00 SELECT UNION g_order g_order_his
# 10 0xBA785E52C7D7EABF 34.2229 1.3% 392 0.0873 0.00 SELECT C?P?TestTable
# 11 0x8FB06F7C0404D7F1 31.5801 1.2% 321 0.0984 0.01 SELECT g_order wm_supplier
# 12 0x81E8830DFA110CBE 30.3748 1.2% 297 0.1023 0.01 SELECT g_order
# 13 0x557A2F67065BD21F 29.2063 1.1% 5646 0.0052 0.01 SELECT UNION g_order g_order_his
# 14 0x7A19B44ECA562BF9 26.4428 1.0% 45527 0.0006 0.00 SELECT website.g_member_tag
# 15 0x675CF777428789E3 24.3164 0.9% 9068 0.0027 0.00 SELECT UNION g_order_detail g_order_detail_his
# 16 0xDF9FF9899BD9C1DB 21.4665 0.8% 255 0.0842 0.02 SELECT g_order
# 17 0x179C41B92C436D43 20.7457 0.8% 171 0.1213 0.00 SELECT wm_microblog_main
# 18 0x964A7D56B400D3C0 19.1692 0.7% 795 0.0241 0.00 SELECT wm_supplier
# 19 0xFE66BE96300AC150 18.5642 0.7% 3912 0.0047 0.00 SELECT website.g_staff
# 20 0x36271DC54179F0EC 17.9929 0.7% 296 0.0608 0.00 SELECT g_order g_staff wm_supplier
# 31 0xC13B0564D15958C7 11.1097 0.4% 10 1.1110 0.02 SELECT wm_menu wm_supplier wm_menu_class
# MISC 0xMISC 457.6604 17.4% 119861 0.0038 0.0 <340 ITEMS>
the disk utility under 20% even in busy time,but cpu usage reached 600%,and the box have one phsical cpu with 16 core
here is some output from "show engine innodb status"
--------------
ROW OPERATIONS
--------------
1 queries inside InnoDB, 0 queries in queue
2 read views open inside InnoDB
Main thread process no. 25306, id 140400012154624, state: flushing buffer pool pages
Number of rows inserted 104585626, updated 68377826, deleted 23333783, read 59937025063
20.66 inserts/s, 34.32 updates/s, 0.67 deletes/s, 148420.53 reads/s