MySQL性能优化
平时我们在使用MySQL的时候，怎么评估系统的运行状态，怎么快速定位系统瓶颈，又如何快速解决问题呢？
本文总结了多年来MySQL优化的经验，系统介绍MySQL优化的方法。
OS性能分析
使用top观察top cpu／memory进程
~ top
top - 09:34:29 up 10 days, 20:11, 1 user, load average: 0.61, 0.59, 0.60
Tasks: 208 total, 1 running, 207 sleeping, 0 stopped, 0 zombie
%Cpu0 : 7.0 us, 2.3 sy, 0.0 ni, 90.0 id, 0.3 wa, 0.3 hi, 0.0 si, 0.0 st
%Cpu1 : 3.0 us, 2.7 sy, 0.7 ni, 91.3 id, 2.0 wa, 0.3 hi, 0.0 si, 0.0 st
KiB Mem: 4046820 total, 3851092 used, 195728 free, 133212 buffers
KiB Swap: 0 total, 0 used, 0 free. 270700 cached Mem
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
1035 root 20 0 436892 260444 2444 S 4.0 6.4 91:51.04 celery
9644 root 25 5 845648 120256 1808 S 1.3 3.0 60:00.06 python
3718 root 20 0 808752 6292 2224 S 0.7 0.2 27:55.43 AliHids
4322 root 20 0 250296 5020 2016 S 0.7 0.1 2:28.77 zabbix_server
16331 admin 20 0 1575644 307948 1252 S 0.7 7.6 5:04.47 ruby2.1
22518 997 20 0 759948 251540 1184 S 0.7 6.2 73:24.72 mysqld
7 root 20 0 0 0 0 S 0.3 0.0 16:37.29 rcu_sched
8 root 20 0 0 0 0 S 0.3 0.0 15:10.74 rcuos/0top - 09:35:29 up 10 days, 20:12, 1 user, load average: 0.22, 0.48, 0.56
Tasks: 207 total, 4 running, 203 sleeping, 0 stopped, 0 zombie
%Cpu(s): 4.5 us, 2.5 sy, 0.7 ni, 90.8 id, 1.2 wa, 0.3 hi, 0.0 si, 0.0 st
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
13103 mysql 20 0 1752220 580048 3852 S 0.3 14.3 5:01.95 mysqld
16331 admin 20 0 1575644 307948 1252 S 0.0 7.6 5:04.62 ruby2.1
1035 root 20 0 436892 260444 2444 S 2.0 6.4 91:52.69 celery
1034 root 20 0 433440 256924 2436 S 0.0 6.3 92:49.27 celery
13841 admin 20 0 681696 254392 2364 S 0.0 6.3 0:03.20 ruby2.1
13844 admin 20 0 681564 254180 2360 S 0.0 6.3 0:03.21 ruby2.1
13838 admin 20 0 680188 252484 2276 S 0.0 6.2 0:02.68 ruby2.1
22518 997 20 0 759948 251536 1180 S 0.7 6.2 73:24.95 mysqld
13189 admin 20 0 675812 250620 2448 S 0.0 6.2 0:21.44 ruby2.1
9644 root 25 5 845648 120300 1808 S 2.0 3.0 60:01.63 python使用mpstat观察每个CPU核心的CPU使用情况
~ mpstat -P ALL 1
Linux 3.13.0-32-generic (dtstack-dev1) 04/16/2016 _x86_64_ (2 CPU)
09:36:22 AM CPU %usr %nice %sys %iowait %irq %soft %steal %guest %gnice %idle
09:36:23 AM all 3.02 0.50 2.01 1.01 0.00 0.00 0.00 0.00 0.00 93.47
09:36:23 AM 0 3.00 0.00 1.00 0.00 1.00 0.00 0.00 0.00 0.00 95.00
09:36:23 AM 1 2.97 0.99 2.97 1.98 0.00 0.00 0.00 0.00 0.00 91.09使用iostat观察系统io状况
~ iostat -kx 3
Linux 3.13.0-32-generic (dtstack-dev1) 04/16/2016 _x86_64_ (2 CPU)
avg-cpu: %user %nice %system %iowait %steal %idle
6.86 0.18 3.08 3.41 0.09 86.39
Device: rrqm/s wrqm/s r/s w/s rkB/s wkB/s avgrq-sz avgqu-sz await r_await w_await svctm %util
xvda 1.13 18.64 14.80 50.55 237.69 804.84 31.91 1.38 21.16 58.68 10.18 1.14 7.48使用sar -n DEV观察网卡流量
~ sar -n DEV 3
Linux 3.13.0-32-generic (dtstack-dev1) 04/16/2016 _x86_64_ (2 CPU)
09:40:02 AM IFACE rxpck/s txpck/s rxkB/s txkB/s rxcmp/s txcmp/s rxmcst/s %ifutil
09:40:05 AM veth9b40f2c 68.67 64.67 5.81 6.50 0.00 0.00 0.00 0.00
09:40:05 AM eth0 76.33 69.00 5.26 5.79 0.00 0.00 0.00 0.00
09:40:05 AM eth1 162.33 159.00 26.10 27.22 0.00 0.00 0.00 0.00
09:40:05 AM lo 133.00 133.00 30.23 30.23 0.00 0.00 0.00 0.00使用vmstat查看系统内存使用情况
~ vmstat -w 3 100
procs ---------------memory-------------- ---swap-- -----io---- -system-- ------cpu-----
r b swpd free buff cache si so bi bo in cs us sy id wa st
0 0 0 265108 119284 218556 0 0 119 403 19 1 7 3 86 3 0
0 0 0 261616 119316 222416 0 0 4 6096 1198 1732 8 4 81 7 0查看系统日志
~ tail -2 /var/log/kern.log
Apr 16 04:07:18 localhost kernel: [917047.906866] Out of memory: Kill process 2063 (ruby2.1) score 84 or sacrifice child
Apr 16 04:07:18 localhost kernel: [917047.907696] Killed process 2063 (ruby2.1) total-vm:710128kB, anon-rss:342320kB, file-rss:0kB
使用dstat
~ dstat -a -i --tcp --vm
----total-cpu-usage---- -dsk/total- -net/total- ---paging-- ---system-- ----interrupts--- ----tcp-sockets---- -----virtual-memory----
usr sys idl wai hiq siq| read writ| recv send| in out | int csw | 77 78 79 |lis act syn tim clo|majpf minpf alloc free
7 3 86 3 0 0| 475k 1610k| 0 0 | 0 0 |1138 1972 | 70 127 68 | 20 117 0 545 0| 5 6100 3234 3242
2 2 95 1 1 0|8192B 928k| 149k 138k| 0 0 |1005 2396 | 30 97 10 | 20 117 1 546 0| 0 1357 544 818
2 2 94 2 0 0| 0 984k| 23k 27k| 0 0 | 958 1687 | 39 198 8 | 20 118 0 547 0| 0 2880 1324 1053记录和查看历史数据
~ dpkg -l | grep sysstat
ii sysstat 10.2.0-1 amd64 system performance tools for Linux
cron.d cat /etc/cron.d/sysstat
# The first element of the path is a directory where the debian-sa1
# script is located
PATH=/usr/lib/sysstat:/usr/sbin:/usr/sbin:/usr/bin:/sbin:/bin
# Activity reports every 10 minutes everyday
5-55/10 * * * * root command -v debian-sa1 > /dev/null && debian-sa1 1 1
# Additional run at 23:59 to rotate the statistics file
59 23 * * * root command -v debian-sa1 > /dev/null && debian-sa1 60 2查看昨天的数据
cron.d sar -u -1 | head
Linux 3.13.0-32-generic (dtstack-dev1) 04/15/2016 _x86_64_ (2 CPU)
12:00:01 AM CPU %user %nice %system %iowait %steal %idle
12:05:01 AM all 9.75 0.78 3.99 5.06 0.10 80.31
12:15:01 AM all 9.59 0.83 3.84 4.27 0.10 81.37
12:25:01 AM all 8.90 0.83 3.78 4.22 0.10 82.17查看swap
cron.d sar -W | head
Linux 3.13.0-32-generic (dtstack-dev1) 04/16/2016 _x86_64_ (2 CPU)
12:00:01 AM pswpin/s pswpout/s
12:05:01 AM 0.00 0.00
12:15:01 AM 0.00 0.00
12:25:01 AM 0.00 0.00查看load
cron.d sar -q | head
Linux 3.13.0-32-generic (dtstack-dev1) 04/16/2016 _x86_64_ (2 CPU)
12:00:01 AM runq-sz plist-sz ldavg-1 ldavg-5 ldavg-15 blocked
12:05:01 AM 4 511 0.14 0.34 0.39 0
12:15:01 AM 6 512 0.14 0.30 0.37 0
12:25:01 AM 3 507 0.41 0.40 0.41 0
查看IO使用情况
cron.d sar -d | head
Linux 3.13.0-32-generic (dtstack-dev1) 04/16/2016 _x86_64_ (2 CPU)
12:00:01 AM DEV tps rd_sec/s wr_sec/s avgrq-sz avgqu-sz await svctm %util
12:05:01 AM dev202-0 81.14 143.50 2076.97 27.37 0.61 7.47 1.36 11.00
12:15:01 AM dev202-0 62.26 47.31 1836.64 30.26 0.56 8.97 1.29 8.02
12:25:01 AM dev202-0 67.85 46.25 1904.55 28.75 0.52 7.59 1.28 8.72查看内存使用情况
cron.d sar -r | head
Linux 3.13.0-32-generic (dtstack-dev1) 04/16/2016 _x86_64_ (2 CPU)
12:00:01 AM kbmemfree kbmemused %memused kbbuffers kbcached kbcommit %commit kbactive kbinact kbdirty
12:05:01 AM 238284 3808536 94.11 95652 180648 6231508 153.99 3486028 135316 0
12:15:01 AM 280972 3765848 93.06 82324 173376 6215156 153.58 3437744 142076 0
12:25:01 AM 240208 3806612 94.06 110392 190312 6195792 153.10 3467544 153012 0查看多核CPU使用情况
cron.d sar -u -P ALL | head
Linux 3.13.0-32-generic (dtstack-dev1) 04/16/2016 _x86_64_ (2 CPU)
12:00:01 AM CPU %user %nice %system %iowait %steal %idle
12:05:01 AM all 7.31 0.80 3.59 4.41 0.10 83.80
12:05:01 AM 0 7.89 0.93 3.95 6.55 0.06 80.61
12:05:01 AM 1 6.72 0.68 3.24 2.26 0.13 86.97MySQL性能分析
配置slowlog
mysql> show variables like 'long_query_time';
+-----------------+----------+
| Variable_name | Value |
+-----------------+----------+
| long_query_time | 2.000000 |
+-----------------+----------+
1 row in set (0.00 sec)
mysql> show variables like '%slow%';
+---------------------------+--------------------------------------+
| Variable_name | Value |
+---------------------------+--------------------------------------+
| log_slow_admin_statements | OFF |
| log_slow_slave_statements | OFF |
| slow_launch_time | 2 |
| slow_query_log | OFF |
| slow_query_log_file | /var/lib/mysql/dtstack-dev1-slow.log |
mysql> set global slow_query_log=ON;
Query OK, 0 rows affected (0.06 sec)
mysql> set global long_query_time=0.01;
Query OK, 0 rows affected (0.02 sec)分析slow log
# User@Host: dtlog[dtlog] @ [10.0.0.5] Id: 279883
# Query_time: 0.012148 Lock_time: 0.000088 Rows_sent: 0 Rows_examined: 0
use dtops_perf;
SET timestamp=1460773285;
insert into dtops_process_stat(user_id, tenant_id,
host_name, proc_exec, proc_args, proc_cnt, cpu_used, io_read_mb, io_write_mb, mem_rss_mb, check_time
) values (
1,1,'iZ233z4w1cdZ', 'python', '/usr/bin/python manage.py runserver 0.0.0.0:8000 ', '1', '0.71', '0.0', '0.02734375', '490.796875', '2016-04-16 02:21:25.636334'
);使用pk-query-digest
mysql pt-query-digest dtstack-dev1-slow.log | head -100
# 540ms user time, 20ms system time, 26.32M rss, 84.35M vsz
# Current date: Sat Apr 16 10:30:05 2016
# Hostname: dtstack-dev1
# Files: dtstack-dev1-slow.log
# Overall: 1.04k total, 46 unique, 0.00 QPS, 0.00x concurrency ___________
# Time range: 2016-02-18 18:00:39 to 2016-04-16 10:29:08
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 15021s 3ms 110s 14s 40s 15s 15s
# Lock time 5141s 0 69s 5s 18s 7s 1s
# Rows sent 92.31k 0 6.53k 91.15 329.68 313.17 0
# Rows examine 785.62k 0 360.68k 775.77 329.68 14.45k 0
# Query size 265.90k 6 1.69k 262.57 874.75 332.24 56.92
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ================== =============== ===== ======= ===== ============
# 1 0x8D6600C5091DA2FB 2545.6864 16.9% 83 30.6709 3.77 INSERT dtops_mysql_stat
# 2 0xFA23984B8E060B24 2179.4857 14.5% 53 41.1224 10.99 SELECT INFORMATION_SCHEMA.INNODB_METRICS
# 3 0x28FC5B5D583E2DA6 1773.7506 11.8% 83 21.3705 0.48 SHOW GLOBAL STATUS
# 4 0xE2A7DFF3037A3A81 1537.1841 10.2% 80 19.2148 0.53 SHOW /*!50003 GLOBAL*/ STATUS
# 5 0xAC0F6B2C861D21D7 826.3786 5.5% 31 26.6574 6.46 SELECT ecs_ecsinstance
# 6 0x026EA5484A97C3C0 801.5408 5.3% 31 25.8562 3.18 SELECT information_schema.processlist
# 7 0x94F6F954ED486D6F 791.8242 5.3% 23 34.4271 9.62 SELECT ecs_ecsdisk
# 8 0xD8AB5099D4B1CC21 675.0423 4.5% 30 22.5014 0.57 SELECT auth_user
# 9 0xDE28A3CBA34F3335 589.1568 3.9% 26 22.6599 1.72 SHOW /*!40003 GLOBAL*/ VARIABLES
# 10 0x0ED17AA0B68A517F 521.2626 3.5% 29 17.9746 10.80 INSERT dtops_linux_stat
# 11 0x53168008EC50F512 358.3756 2.4% 29 12.3578 0.17 SELECT
# 12 0x3EB3BC982F72ED66 319.3946 2.1% 13 24.5688 1.07 INSERT dtops_disk_free
# 13 0x50C47AC11BB2ABD8 280.2534 1.9% 14 20.0181 2.62 SELECT ecs_hourinstancemonitordata
# 14 0x3783A78AF527ACA4 207.8257 1.4% 10 20.7826 2.79 SELECT dtops_host_list
# 15 0xEF2E30AE81C60FE3 192.6594 1.3% 18 10.7033 13.90 INSERT dtops_disk_stat
# 16 0xEE7686F2E0817183 181.4489 1.2% 7 25.9213 5.01 SELECT ecs_ecsinstancestatistic
# 17 0x6238F0E765A0C029 133.1747 0.9% 5 26.6349 0.99 SELECT information_schema.innodb_trx information_schema.innodb_lock_waits
# 18 0x577997B04D055D37 114.8435 0.8% 5 22.9687 2.10 SHOW TABLES
# 19 0xED823F6211063056 106.3436 0.7% 4 26.5859 3.22 UPDATE ecs_ecsinstancestatistic
# 20 0xD2BA5922D8365D80 86.9031 0.6% 2 43.4515 0.16 SELECT rds_rdssqlreport
# MISC 0xMISC 798.2521 5.3% 461 1.7316 0.0 <26 ITEMS>
# Query 1: 0.00 QPS, 0.00x concurrency, ID 0x8D6600C5091DA2FB at byte 144946
# This item is included in the report because it matches --limit.
# Scores: V/M = 3.77
# Time range: 2016-02-18 22:22:02 to 2016-03-01 14:03:43
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 8 83
# Exec time 16 2546s 13s 83s 31s 42s 11s 29s
# Lock time 30 1549s 1s 69s 19s 32s 11s 17s
# Rows sent 0 0 0 0 0 0 0 0
# Rows examine 0 0 0 0 0 0 0 0
# Query size 26 71.63k 866 912 883.69 874.75 20.83 874.75
# String:
# Databases dtops_perf
# Hosts dtstack-dev1
# Users lazydba
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms
# 10ms
# 100ms
# 1s
# 10s+ ################################################################
# Tables
# SHOW TABLE STATUS FROM `dtops_perf` LIKE 'dtops_mysql_stat'\G
# SHOW CREATE TABLE `dtops_perf`.`dtops_mysql_stat`\G
insert into dtops_mysql_stat(user_id, tenant_id, instance_name, innodb_rows_deleted, threads_connected, innodb_buffer_pool_pages_flushed, ins, innodb_os_log_written, innodb_rows_updated, innodb_data_fsyncs, select_scan, questions, innodb_log_writes, innodb_data_read, qps, open_files, sel, recv, threads_running, innodb_rows_read, innodb_rows_inserted, innodb_row_lock_waits, sort_rows, innodb_row_lock_time_avg, upd, open_tables, innodb_data_written, sqps, innodb_data_writes, tps, innodb_bp_reads, innodb_buffer_pool_pages_dirty, del, innodb_data_reads, innodb_bp_read_requests, sent, innodb_os_log_fsyncs, check_time)
values(1,1,'dtstack-dev:3306', '0', '14', '1', '0', '204', '0', '1', '2', '8', '0', '0', '2', '-1', '2', '690', '5', '0', '0', '0', '0', '0', '0', '0', '39628', '0', '1', '0', '0', '0', '0', '0', '3', '14535', '0', '2016-02-26 16:31:50.036858')\GTCPDUMP + pt-query-digest
# tcpdump -s 65535 -i any -c 1000 port 3306 -w tmp.pcap
tcpdump: listening on any, link-type LINUX_SLL (Linux cooked), capture size 65535 bytes
1000 packets captured
1323 packets received by filter
0 packets dropped by kernel
# tcpdump -r tmp.pcap -s 65535 -x -nn -q -tttt | pt-query-digest --type tcpdump
reading from file tmp.pcap, link-type LINUX_SLL (Linux cooked)
Reading from STDIN ...
TCP session 192.168.0.1:53744 had errors, will save them in /tmp/pt-query-digest-errors.dYTKmpS
# 480ms user time, 20ms system time, 28.12M rss, 86.31M vsz
# Current date: Sat Apr 16 10:57:03 2016
# Hostname: dtstack-dev1
# Files: STDIN
# Overall: 131 total, 38 unique, 28.04 QPS, 0.03x concurrency ____________
# Time range: 2016-04-16 10:56:21.810539 to 10:56:26.482281
# Attribute total min max avg 95% stddev median
# ============ ======= ======= ======= ======= ======= ======= =======
# Exec time 128ms 0 18ms 976us 5ms 3ms 98us
# Rows affecte 51 0 10 0.39 0.99 1.37 0
# Query size 14.78k 6 920 115.52 537.02 204.71 26.08
# Warning coun 0 0 0 0 0 0 0
# Boolean:
# No index use 12% yes, 87% no
# Profile
# Rank Query ID Response time Calls R/Call V/M Item
# ==== ================== ============= ===== ====== ===== ===============
# 1 0x5D51E5F01B88B79E 0.0667 52.1% 12 0.0056 0.01 ADMIN CONNECT
# 2 0x11D0C2162F1C5721 0.0216 16.9% 2 0.0108 0.01 INSERT dtops_disk_stat
# 3 0x0ED17AA0B68A517F 0.0154 12.0% 2 0.0077 0.00 INSERT dtops_linux_stat
# 4 0x0E9D1E6D473DBD20 0.0052 4.1% 1 0.0052 0.00 SELECT hosts items functions triggers
# 5 0x251BDDE46C5899A9 0.0034 2.6% 1 0.0034 0.00 SELECT hosts items functions triggers
# 6 0x3AEAAD0E15D725B5 0.0015 1.2% 24 0.0001 0.00 SET
# 7 0x4256B25BD80D888C 0.0013 1.0% 4 0.0003 0.00 SELECT dtuic_userprofile
# 8 0x860902B0157FAFD9 0.0012 0.9% 5 0.0002 0.00 INSERT history_uint
# 9 0x60038AB9468C9A61 0.0009 0.7% 1 0.0009 0.00 SELECT items hosts
# 10 0x8A10718E7D316421 0.0009 0.7% 8 0.0001 0.00 BEGIN
# 11 0xCC47B42511EA22DD 0.0009 0.7% 12 0.0001 0.00 SET
# 12 0x3B93991D5396A384 0.0008 0.6% 12 0.0001 0.00 SET
# 13 0x2719E98AB2E682FE 0.0007 0.5% 2 0.0003 0.00 UPDATE hosts
# 14 0xAC7F5F65B4A51C07 0.0006 0.5% 8 0.0001 0.00 COMMIT
# 15 0xBF081E5AB46DF811 0.0006 0.4% 1 0.0006 0.00 SELECT httptest hosts
# MISC 0xMISC 0.0063 5.0% 36 0.0002 0.0 <23 ITEMS>
# Query 1: 12.87 QPS, 0.07x concurrency, ID 0x5D51E5F01B88B79E at byte 1657076
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.01
# Time range: 2016-04-16 10:56:23.901443 to 10:56:24.833671
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 9 12
# Exec time 52 67ms 279us 18ms 6ms 16ms 7ms 445us
# Rows affecte 0 0 0 0 0 0 0 0
# Query size 2 360 30 30 30 30 0 30
# Warning coun 0 0 0 0 0 0 0 0
# String:
# Databases dtuicmysq... (8/66%), (4/33%)
# Hosts 192.168.1.3 (8/66%), 218.74.37.4 (4/33%)
# Users dtcloud_de... (8/66%), dtlog (4/33%)
# Query_time distribution
# 1us
# 10us
# 100us ################################################################
# 1ms
# 10ms ################################
# 100ms
# 1s
# 10s+
administrator command: Connect\G
# Query 2: 2.57 QPS, 0.03x concurrency, ID 0x11D0C2162F1C5721 at byte 1660770
# This item is included in the report because it matches --limit.
# Scores: V/M = 0.01
# Time range: 2016-04-16 10:56:24.096396 to 10:56:24.874351
# Attribute pct total min max avg 95% stddev median
# ============ === ======= ======= ======= ======= ======= ======= =======
# Count 1 2
# Exec time 16 22ms 5ms 16ms 11ms 16ms 8ms 11ms
# Rows affecte 3 2 1 1 1 1 0 1
# Query size 6 962 481 481 481 481 0 481
# Warning coun 0 0 0 0 0 0 0 0
# String:
# Databases
# Hosts 123.74.33.4
# Users dtlog
# Query_time distribution
# 1us
# 10us
# 100us
# 1ms ################################################################
# 10ms ################################################################
# 100ms
# 1s
# 10s+
# Tables
# SHOW TABLE STATUS FROM `1` LIKE 'dtops_disk_stat'\G
# SHOW CREATE TABLE `1`.`dtops_disk_stat`\G
insert into dtops_disk_stat(
user_id, tenant_id, host_name, disk_name,
rd_s, rd_avgkb, rd_mb_s, rd_mrg_s, rd_cnc, rd_rt,
wr_s, wr_avgkb, wr_mb_s, wr_mrg_s, wr_cnc, wr_rt,
busy, in_prg, io_s, qtime, stime,
check_time)
values
(1, 1, 'test01', 'sda', '0.0','0.0','0.0','0.0','0.0','0.0','6.4','11.56','0.07','1.0','0.07','10.0','6.48','0.0','6.4','1.24','8.76','2016-04-16 02:54:12.369120')
\G通过processlist查看系统当前运行情况
mysql> select * from information_schema.processlist where command !='Sleep' order by time desc limit 10\G
*************************** 1. row ***************************
ID: 292486
USER: root
HOST: localhost
DB: NULL
COMMAND: Query
TIME: 0
STATE: executing
INFO: select * from information_schema.processlist where command !='Sleep' order by time desc limit 10通过genenral log查看系统运行的SQL
mysql> show variables like '%general%';
+------------------+---------------------------------+
| Variable_name | Value |
+------------------+---------------------------------+
| general_log | OFF |
| general_log_file | /var/lib/mysql/dtstack-dev1.log |
+------------------+---------------------------------+
2 rows in set (0.00 sec)
mysql> set global general_log=ON;
tail -10f /var/lib/mysql/dtstack-dev1.log
294645 Query SET NAMES utf8
294645 Query set autocommit=0
294645 Query set autocommit=1
294645 Query SET SQL_AUTO_IS_NULL = 0
294645 Quit
294646 Connect user@host on dtuic
294646 Query SET NAMES utf8
294646 Query set autocommit=0
294646 Query set autocommit=1
294646 Query SET SQL_AUTO_IS_NULL = 0
294646 Query SELECT * FROM `dtuic_userprofile` WHERE `dtuic_userprofile`.`agent_token` = 'xx'
294646 Quit
294648 Connect user@host on dtops_db
294648 Query SET NAMES utf8
294648 Query SET NAMES utf8
294648 Query set autocommit=0
294648 Query set autocommit=1
294648 Query SET SQL_AUTO_IS_NULL = 0
294648 Query insert into dtops_linux_stat(user_id, tenant_id, host_name, load1, load5, load15, cpu_usr, cpu_sys, cpu_idle, cpu_wai, mem_used, mem_free, mem_buff, mem_cache, swap_used, swap_free, io_read, io_write, io_queue, io_await, io_svctm, io_util, io_read_mb, io_write_mb, net_recv, net_send, proc_run, proc_blk, proc_new, intr, csw, softirq, page_in, page_out, swap_in, swap_out, page_fault, page_mjfault, check_time) values(1, 1, 'test01', '0.63', '0.72', '0.79', '6.44', '1.21', '91.4', '0.95', '9264.0', '281.0', '253.0', '5851.0', '15680.0', '696.0', '0.0', '11.2', '0.0', '13.15', '5.15', '6.8', '0.0', '0.1', '1.2', '1.46', '0.4', '1.0', '0.0', '9953.4', '10081.6', '516.6', '0.0', '102.0', '0.0', '0.0', '13.0', '0.0', '2016-04-16 02:39:03.487738')
294648 Quit通过binlog查看系统DML
root@test01:/var/lib/my3307# mysqlbinlog -v mysql-bin.000002 > tmp.sql
root@test01:/var/lib/my3307# head -100 tmp.sql
/*!50530 SET @@SESSION.PSEUDO_SLAVE_MODE=1*/;
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#160413 19:28:37 server id 10 end_log_pos 120 CRC32 0xef6cb6a8 Start: binlog v 4, server v 5.6.29-log created 160413 19:28:37
# Warning: this binlog is either in use or was not closed properly.
BINLOG '
ZS0OVw8KAAAAdAAAAHgAAAABAAQANS42LjI5LWxvZwAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAAA
AAAAAAAAAAAAAAAAAAAAAAAAEzgNAAgAEgAEBAQEEgAAXAAEGggAAAAICAgCAAAACgoKGRkAAai2
bO8=
'/*!*/;
# at 120
#160413 19:28:37 server id 10 end_log_pos 191 CRC32 0xaaca06a8 Previous-GTIDs
# 08eef41e-df72-11e5-be92-0024e84cb72f:1-12
# at 191
#160413 19:29:43 server id 6033 end_log_pos 239 CRC32 0xde16d70b GTID [commit=yes]
SET @@SESSION.GTID_NEXT= '08eef41e-df72-11e5-be92-0024e84cb72f:13'/*!*/;
# at 239
#160413 19:29:43 server id 6033 end_log_pos 333 CRC32 0x61812d71 Query thread_id=539 exec_time=0 error_code=0
SET TIMESTAMP=1460546983/*!*/;
SET @@session.pseudo_thread_id=539/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=1075838976/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
create database hell
/*!*/;
# at 333
#160413 20:10:37 server id 10 end_log_pos 381 CRC32 0x590a33e4 GTID [commit=yes]
SET @@SESSION.GTID_NEXT= 'c59b9266-0090-11e6-968b-0024e84cb72f:1'/*!*/;
# at 381
#160413 20:10:37 server id 10 end_log_pos 472 CRC32 0x1b5e7367 Query thread_id=512 exec_time=0 error_code=0
SET TIMESTAMP=1460549437/*!*/;
create database yyy
# at 863
#160413 20:14:21 server id 6033 end_log_pos 906 CRC32 0xfd739e72 Table_map: `xxx`.`a` mapped to number 71
# at 906
#160413 20:14:21 server id 6033 end_log_pos 946 CRC32 0x5d365030 Write_rows: table id 71 flags: STMT_END_F
BINLOG '
HTgOVxORFwAAKwAAAIoDAAAAAEcAAAAAAAEAA3h4eAABYQABAwABcp5z/Q==
HTgOVx6RFwAAKAAAALIDAAAAAEcAAAAAAAEAAgAB//5kAAAAMFA2XQ==
'/*!*/;
### INSERT INTO `xxx`.`a`
### SET
### @1=100
# at 946
查看MySQL错误日志
mysql> show variables like 'log_error';
+---------------+--------------------------+
| Variable_name | Value |
+---------------+--------------------------+
| log_error | /var/log/mysql/error.log |
$ tail -100 /var/log/mysql/error.log
2016-04-12 20:38:21 25937 [Warning] Slave: Operation DROP USER failed for 'monitor'@'127.0.0.1' Error_code: 1396
2016-04-12 20:38:21 25937 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'mysql-bin.000002' position 2461
2016-04-13 19:28:37 25937 [Note] @@GLOBAL.GTID_PURGED was changed from '' to '08eef41e-df72-11e5-be92-0024e84cb72f:1-12'.
2016-04-13 19:28:37 25937 [Note] @@GLOBAL.GTID_EXECUTED was changed from '' to '08eef41e-df72-11e5-be92-0024e84cb72f:1-12'.
2016-04-13 19:29:04 25937 [Warning] Slave SQL: If a crash happens this configuration does not guarantee that the relay log info will be consistent, Error_code: 0
2016-04-13 19:29:04 25937 [Note] Slave SQL thread initialized, starting replication in log 'mysql-bin.000002' at position 2461, relay log './mysqld-relay-bin.000003' position: 1178
2016-04-13 20:11:50 25937 [Note] Error reading relay log event: slave SQL thread was killed
2016-04-13 20:11:50 25937 [ERROR] Error reading packet from server: Lost connection to MySQL server during query ( server_errno=2013)
2016-04-13 20:11:50 25937 [Note] Slave I/O thread killed while reading event
2016-04-13 20:11:50 25937 [Note] Slave I/O thread exiting, read up to log 'mysql-bin.000002', position 346980查看MySQL状态
mysql> show global status like '%threads_runn%';
+-----------------+-------+
| Variable_name | Value |
+-----------------+-------+
| Threads_running | 1 |
+-----------------+-------+
| Com_select | 307064 |
| Com_insert | 203395 |
| Com_delete | 0 |
| Com_update | 32287 |
mysql> show global status like '%innodb_rows%';
+----------------------+----------+
| Variable_name | Value |
+----------------------+----------+
| Innodb_rows_deleted | 0 |
| Innodb_rows_inserted | 184427 |
| Innodb_rows_read | 26099334 |
| Innodb_rows_updated | 32551 |
show global status like '%innodb_buffer_pool_pages%';
+----------------------------------+--------+
| Variable_name | Value |
+----------------------------------+--------+
| Innodb_buffer_pool_pages_data | 6901 |
| Innodb_buffer_pool_pages_dirty | 69 |
| Innodb_buffer_pool_pages_flushed | 205928 |
| Innodb_buffer_pool_pages_free | 1024 |
| Innodb_buffer_pool_pages_misc | 266 |
| Innodb_buffer_pool_pages_total | 8191 |
mysql> show global status like '%innodb_buffer_pool_read%';
+---------------------------------------+----------+
| Variable_name | Value |
+---------------------------------------+----------+
| Innodb_buffer_pool_read_ahead_rnd | 0 |
| Innodb_buffer_pool_read_ahead | 2426 |
| Innodb_buffer_pool_read_ahead_evicted | 0 |
| Innodb_buffer_pool_read_requests | 16119505 |
| Innodb_buffer_pool_reads | 6115 |
mysql> show global status like '%innodb_row_lock%';
+-------------------------------+-------+
| Variable_name | Value |
+-------------------------------+-------+
| Innodb_row_lock_current_waits | 0 |
| Innodb_row_lock_time | 10 |
| Innodb_row_lock_time_avg | 0 |
| Innodb_row_lock_time_max | 2 |
| Innodb_row_lock_waits | 22 |
mysqladmin extended-status -i 3 -r | grep -i innodb_rows
| Innodb_rows_deleted | 0 |
| Innodb_rows_inserted | 182053 |
| Innodb_rows_read | 25740195 |
| Innodb_rows_updated | 32287 |
| Innodb_rows_deleted | 0 |
| Innodb_rows_inserted | 43 |
| Innodb_rows_read | 943 |
| Innodb_rows_updated | 0 |
| Innodb_rows_deleted | 0 |
| Innodb_rows_inserted | 8 |
| Innodb_rows_read | 390 |
| Innodb_rows_updated | 0 |查看Innodb状态
mysql> show engine innodb status\G
*************************** 1. row ***************************
Type: InnoDB
Name:
Status:
=====================================
2016-04-16 12:02:59 7fef13d0d700 INNODB MONITOR OUTPUT
=====================================
Per second averages calculated from the last 47 seconds
-----------------
BACKGROUND THREAD
-----------------
srv_master_thread loops: 15203 srv_active, 0 srv_shutdown, 13276 srv_idle
srv_master_thread log flush and writes: 28472
----------
SEMAPHORES
----------
OS WAIT ARRAY INFO: reservation count 49397
OS WAIT ARRAY INFO: signal count 49296
Mutex spin waits 47682, rounds 1356865, OS waits 44752
RW-shared spins 3909, rounds 116413, OS waits 3858
RW-excl spins 828, rounds 24083, OS waits 755
Spin rounds per wait: 28.46 mutex, 29.78 RW-shared, 29.09 RW-excl
------------
TRANSACTIONS
------------
Trx id counter 65462789
Purge done for trx's n:o < 65461073 undo n:o < 0 state: running but idle
History list length 2881
LIST OF TRANSACTIONS FOR EACH SESSION:
---TRANSACTION 0, not started
MySQL thread id 349713, OS thread handle 0x7fef13d0d700, query id 2399249 localhost root init
show engine innodb status
---TRANSACTION 65462442, not started
MySQL thread id 355002, OS thread handle 0x7fef13c76700, query id 2396568 180.173.242.219 dtcloud_dev cleaning up
---TRANSACTION 65396897, not started
MySQL thread id 316553, OS thread handle 0x7fef13e02700, query id 2129942 180.173.242.219 dtcloud_dev cleaning up
---TRANSACTION 65352135, not started
MySQL thread id 288067, OS thread handle 0x7fef13bb2700, query id 1941170 180.173.242.219 dtcloud_dev cleaning up
---TRANSACTION 65327485, not started
MySQL thread id 274710, OS thread handle 0x7fef13c45700, query id 1847425 180.173.242.219 dtcloud_dev cleaning up
--------
FILE I/O
--------
I/O thread 0 state: waiting for completed aio requests (insert buffer thread)
I/O thread 1 state: waiting for completed aio requests (log thread)
I/O thread 2 state: waiting for completed aio requests (read thread)
I/O thread 3 state: waiting for completed aio requests (read thread)
I/O thread 4 state: waiting for completed aio requests (read thread)
I/O thread 5 state: waiting for completed aio requests (read thread)
I/O thread 6 state: waiting for completed aio requests (write thread)
I/O thread 7 state: waiting for completed aio requests (write thread)
I/O thread 8 state: waiting for completed aio requests (write thread)
I/O thread 9 state: waiting for completed aio requests (write thread)
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
9793 OS file reads, 457309 OS file writes, 263759 OS fsyncs
0.00 reads/s, 0 avg bytes/read, 18.87 writes/s, 10.87 fsyncs/s
-------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
-------------------------------------
Ibuf: size 1, free list len 11, seg size 13, 551 merges
merged operations:
insert 1709, delete mark 0, delete 0
discarded operations:
insert 0, delete mark 0, delete 0
Hash table size 276671, node heap has 266 buffer(s)
13.79 hash searches/s, 21.34 non-hash searches/s
---
LOG
---
Log sequence number 9675441693
Log flushed up to 9675441693
Pages flushed up to 9675441693
Last checkpoint at 9675441693
0 pending log writes, 0 pending chkp writes
243472 log i/o's done, 9.98 log i/o's/second
----------------------
BUFFER POOL AND MEMORY
----------------------
Total memory allocated 137363456; in additional pool allocated 0
Dictionary memory allocated 1945330
Buffer pool size 8191
Free buffers 1024
Database pages 6901
Old database pages 2527
Modified db pages 0
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
Pages made young 20983, not young 80923
0.00 youngs/s, 0.00 non-youngs/s
Pages read 9086, created 2328, written 207366
0.00 reads/s, 0.06 creates/s, 8.60 writes/s
Buffer pool hit rate 1000 / 1000, young-making rate 0 / 1000 not 0 / 1000
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
LRU len: 6901, unzip_LRU len: 0
I/O sum[398]:cur[6], unzip sum[0]:cur[0]
--------------
ROW OPERATIONS
--------------
0 queries inside InnoDB, 0 queries in queue
0 read views open inside InnoDB
Main thread process no. 13103, id 140664767006464, state: sleeping
Number of rows inserted 186160, updated 33021, deleted 0, read 26128219
7.83 inserts/s, 0.00 updates/s, 0.00 deletes/s, 49.34 reads/s
----------------------------
END OF INNODB MONITOR OUTPUT
============================
1 row in set (0.08 sec)数据库参数调优
MySQL优化器参数
mysql> show variables like '%optimizer%';
+------------------------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| Variable_name | Value |
+------------------------------+--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------+
| optimizer_prune_level | 1 |
| optimizer_search_depth | 62 |
| optimizer_switch | index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,engine_condition_pushdown=on,index_condition_pushdown=on,mrr=on,mrr_cost_based=on,block_nested_loop=on,batched_key_access=off,materialization=on,semijoin=on,loosescan=on,firstmatch=on,subquery_materialization_cost_based=on,use_index_extensions=on |
| optimizer_trace | enabled=off,one_line=off |
| optimizer_trace_features | greedy_search=on,range_optimizer=on,dynamic_range=on,repeated_subselect=on |
| optimizer_trace_limit | 1 |
| optimizer_trace_max_mem_size | 16384 |
| optimizer_trace_offset | -1myisam参数
show variables like '%myisam%';
+---------------------------+----------------------+
| Variable_name | Value |
+---------------------------+----------------------+
| myisam_data_pointer_size | 6 |
| myisam_max_sort_file_size | 9223372036853727232 |
| myisam_mmap_size | 18446744073709551615 |
| myisam_recover_options | OFF |
| myisam_repair_threads | 1 |
| myisam_sort_buffer_size | 8388608 |
| myisam_stats_method | nulls_unequal |
| myisam_use_mmap | OFF |
mysql> show variables like '%key%';
+--------------------------+----------------------+
| Variable_name | Value |
+--------------------------+----------------------+
| delay_key_write | ON |
| foreign_key_checks | ON |
| have_rtree_keys | YES |
| key_buffer_size | 8388608 |
| key_cache_age_threshold | 300 |
| key_cache_block_size | 1024 |
| key_cache_division_limit | 100 |
| max_seeks_for_key | 18446744073709551615 |innodb
mysql> show variables like '%innodb_flush%';
+--------------------------------+-------+
| Variable_name | Value |
+--------------------------------+-------+
| innodb_flush_log_at_timeout | 1 |
| innodb_flush_log_at_trx_commit | 1 |
| innodb_flush_method | |
| innodb_flush_neighbors | 1 |
| innodb_flushing_avg_loops | 30 |
mysql> show variables like '%innodb_buffer%';
+-------------------------------------+----------------+
| Variable_name | Value |
+-------------------------------------+----------------+
| innodb_buffer_pool_dump_at_shutdown | OFF |
| innodb_buffer_pool_dump_now | OFF |
| innodb_buffer_pool_filename | ib_buffer_pool |
| innodb_buffer_pool_instances | 8 |
| innodb_buffer_pool_load_abort | OFF |
| innodb_buffer_pool_load_at_startup | OFF |
| innodb_buffer_pool_load_now | OFF |
| innodb_buffer_pool_size | 134217728 |
mysql> show variables like '%innodb_io%';
+------------------------+-------+
| Variable_name | Value |
+------------------------+-------+
| innodb_io_capacity | 200 |
| innodb_io_capacity_max | 2000 |
mysql> show variables like '%innodb%thread%';
+---------------------------+-------+
| Variable_name | Value |
+---------------------------+-------+
| innodb_purge_threads | 1 |
| innodb_read_io_threads | 4 |
| innodb_thread_concurrency | 0 |
| innodb_thread_sleep_delay | 10000 |
| innodb_write_io_threads | 4 |
mysql> show variables like '%double%';
+--------------------+-------+
| Variable_name | Value |
+--------------------+-------+
| innodb_doublewrite | ON |
mysql> show variables like '%innodb_stats%';
+--------------------------------------+-------------+
| Variable_name | Value |
+--------------------------------------+-------------+
| innodb_stats_auto_recalc | ON |
| innodb_stats_method | nulls_equal |
| innodb_stats_on_metadata | OFF |
| innodb_stats_persistent | ON |
| innodb_stats_persistent_sample_pages | 20 |
| innodb_stats_sample_pages | 8 |
| innodb_stats_transient_sample_pages | 8 |
