systematic approach to performance - percona · systematic approach to performance marcos albe...
TRANSCRIPT
Systematic approach to performance
Marcos Albe & Ryan LowePercona Technical Webinars
2014
www.percona.com
Agenda
● What● Why● The Resources● The Tools● The Percona Tools
www.percona.com
What are we talking about?
How to obtain key metrics and
introspection, about resources and
workload and it's performance.
www.percona.com
Why care about system performance?
● To save money (The Economist)● To solve production issues (The Fireman)● Plan for growth (The Architect)
www.percona.com
The Resources
● CPU● RAM● Storage● Network● Caches, mutexes, buffers are also resources
(all these also utilize hardware)
www.percona.com
The Tools
www.percona.com
The Tools
Linux tools● top # general monitor snapshot
● vmstat # general monitor time series
● iostat # IO / storage
● gdb # Backtraces; Black magic
● oprofile # System-wide profiler
● strace # System calls profiler
● netstat # Network reporting
● ethtool # Network adapter
● tcpdump # TCP packet dumper
www.percona.com
The Tools (cont.)
Percona Toolkit tools● pt-diskstats # a replacement for iostat
● pt-ioprofile # per-process/per-file IO stats
● pt-pmp # Poor Man's Profiler
● pt-mysql-summary # condensed MySQL summary
www.percona.com
top
Tool #1
www.percona.com
H
top
Tool #1: top
www.percona.com
vmstat
Tool #2
www.percona.com
H
Tool #2: vmstat
www.percona.com
iostat
Tool #3
www.percona.com
H
Tool #3:iostat
www.percona.com
oprofile
Tool #4
www.percona.com
# for vm's (vmware and virtualbox at least):opcontrol --deinitmodprobe oprofile timer=1
# disable Non Maskable Interrupt watchdog # used by kernel to detect if CPU is lockedecho 0 > /proc/sys/kernel/nmi_watchdog
# initialize and startopcontrol --initopcontrol --setup --separate=lib,kernel,thread --no-vmlinuxopcontrol --start-daemonopcontrol --start
<...profiler running...>
Tool #4: oprofile
www.percona.com
# dump and reportopcontrol --dumpopreport --demangle=smart \
--symbols \--long-filenames \--merge tgid $(which mysqld)
# terminate and cleanupopcontrol --stopopcontrol --deinitopcontrol --reset
Tool #4: oprofile
www.percona.com
samples % image name symbol name 23296 26.7355 /usr/bin/mysqld my_hash_sort_simple11597 13.3092 /no-vmlinux /no-vmlinux3922 4.5011 /usr/bin/mysqld ptr_compare_02753 3.1595 /usr/bin/mysqld my_strnxfrm_simple2592 2.9747 /usr/bin/mysqld row_search_for_mysql2294 2.6327 /usr/bin/mysqld rec_get_offsets_func2285 2.6224 /usr/bin/mysqld buf_page_is_corrupted1479 1.6974 /usr/bin/mysqld my_qsort21440 1.6526 /usr/bin/mysqld row_sel_store_mysql_rec1266 1.4529 /usr/bin/mysqld hp_write_key923 1.0593 /usr/bin/mysqld heap_rrnd894 1.0260 /usr/bin/mysqld MYSQLparse(void*)838 0.9617 /usr/bin/mysqld buf_calc_page_new_checksum773 0.8871 /usr/bin/mysqld evaluate_join_record(JOIN*, st_join...679 0.7793 /usr/bin/mysqld filesort(THD*, TABLE*, st_sort_field..616 0.7069 /usr/bin/mysqld cmp_dtuple_rec_with_match
Tool #4: oprofile
www.percona.com
gdb
Tool #5
www.percona.com
pthread_cond_wait@@GLIBC_2.3.2 () from /lib64/libpthread..MYSQL_BIN_LOG::wait_for_update from log.cc:5041next_event from slave.cc:4366exec_relay_log_event from slave.cc:2322handle_slave_sql from slave.cc:3148start_thread () from /lib64/libpthread.so.0clone () from /lib64/libc.so.6
Tool #5: gdb
Backtrace sample (slave thread)
www.percona.com
gdb -ex "set pagination 0"\ -ex "thread apply all bt" \ -batch -p `pgrep -x mysqld` > mysql.backtrace
# fullgdb -ex "set pagination 0" \ -ex "thread apply all bt full" \ -batch -p `pgrep -x mysqld` > full-mysql.backtrace
Tool #5: gdb
Getting backtraces with GDB
www.percona.com
pt-pmp -p `pgrep -x mysqld`
10 libaio::??(libaio.so.1), os_aio_linux_collect(os0file.c:4539), os_aio_linux_handle(os0file.c:4539), fil_aio_wait(fil0fil.c:4706), io_handler_thread(srv0start.c:482), start_thread(libpthread.so.0), clone(libc.so.6)
2 write(libpthread.so.0), net_real_write(net_serv.cc:632), net_write_buff(net_serv.cc:527), my_net_write(net_serv.cc:403), Protocol::write(protocol.cc:821), end_send(sql_select.cc:12738), evaluate_join_record(sql_select.cc:11919), sub_select(sql_select.cc:11772), do_select(sql_select.cc:11537), JOIN::exec(sql_select.cc:2385), mysql_select(sql_select.cc:2604), handle_select(sql_select.cc:297), execute_sqlcom_select(sql_parse.cc:4595), mysql_execute_command(sql_parse.cc:2156), mysql_parse(sql_parse.cc:5632), dispatch_command(sql_parse.cc:1037), do_handle_one_connection(sql_connect.cc:853), handle_one_connection(sql_connect.cc:772), start_thread(libpthread.so.0), clone(libc.so.6)
2 my_hash_sort_simple(ctype-simple.c:317), hp_rec_hashnr(hp_hash.c:333), hp_write_key(hp_write.c:339), heap_write(hp_write.c:52), ha_heap::write_row(ha_heap.cc:240), handler::ha_write_row(handler.cc:5188), end_write(sql_select.cc:12934), evaluate_join_record(sql_select.cc:11919), sub_select(sql_select.cc:11772), do_select(sql_select.cc:11537), JOIN::exec(sql_select.cc:1990), mysql_select(sql_select.cc:2604), handle_select(sql_select.cc:297), execute_sqlcom_select(sql_parse.cc:4595), mysql_execute_command(sql_parse.cc:2156), mysql_parse(sql_parse.cc:5632), dispatch_command(sql_parse.cc:1037), do_handle_one_connection(sql_connect.cc:853), handle_one_connection(sql_connect.cc:772), start_thread(libpthread.so.0), clone(libc.so.6)
1 sigwait(libpthread.so.0), signal_hand(mysqld.cc:2700), start_thread(libpthread.so.0), clone(libc.so.6)
Tool #5: gdb
Poor Man's Profiler
www.percona.com
ERROR 1040 (00000): Too many connections!? :)
gdb -ex "set max_connections=5000" \ -batch \ -p `pgrep -x mysqld`
http://www.mysqlperformanceblog.com/2010/03/23/too-many-connections-no-problem/
Tool #5: gdb
Dirty Tricks
www.percona.com
Annoying LSN is in the future filling your error log!? :)
gdb -ex "set log_sys->lsn = 12300000" \ -batch \ -p `pgrep -x mysqld`
http://www.mysqlperformanceblog.com/2013/09/11/how-to-move-the-innodb-log-sequence-number-lsn-forward/
http://dom.as/tag/gdb/ has more fun tricks
Tool #5: gdb
Dirty Tricks
www.percona.com
strace
Tool #6
www.percona.com
Tool #6: strace
Strace to collect statisticsstrace -f -c -Stime -p `pgrep -x mysqld`
% time seconds usecs/call calls errors syscall------ ----------- ----------- --------- --------- ---------------- 84.77 4.749000 31039 153 select 10.95 0.613172 16 38235 4942 futex 3.50 0.195997 6 32647 118 read 0.26 0.014530 1 22950 write 0.22 0.012181 1 17383 pwrite 0.18 0.010000 45 220 fdatasync 0.04 0.002000 2000 1 rt_sigtimedwait 0.03 0.001592 1 1102 open 0.03 0.001474 13 111 mkdir 0.02 0.001043 9 110 madvise 0.01 0.000687 0 8805 8805 sched_setscheduler 0.00 0.000167 0 1321 close 0.00 0.000087 0 440 unlink
www.percona.com
Tool #6: strace
strace -f -tt -s512 -o/tmp/trace --p`pgrep -x mysqld`
10813 14:17:58.199164 read(31, "\25\0\0\0", 4) = 410813 14:18:34.502765 read(31, "\3select * from test.a", 21) = 2110813 14:18:34.503114 open("./test/a.frm", O_RDONLY) = -1 ENOENT (No su...ch file or directory)10813 14:18:34.503430 write(31, "%\0\0\1\377z\4#42S02Table 'test.a' doe..sn't exist", 41) = 4110813 14:18:34.503649 read(31, 0x1c136e0, 4) = -1 EAGAIN (Resource temp...orarily unavailable)10813 14:18:34.503824 read(31, "\22\0\0\0", 4) = 410813 14:18:37.016834 read(31, "\3SELECT DATABASE()", 18) = 1810813 14:18:37.017195 write(31, "\1\0\0\1\1 \0\0\2\3def\0\0\0\nDATABASE()\0\f!\0f\0\0\0\375\0\0\37\0\0\5\0\0\3\376\0...\0\2\0\1\0\0\4\373\5\0\0\5\376\0\0\2\0", 64) = 6410813 14:18:37.017332 read(31, 0x1c136e0, 4) = -1 EAGAIN (Resource temp...orarily unavailable)10813 14:18:37.017443 read(31, "\5\0\0\0", 4) = 410813 14:18:37.017637 read(31, "\2test", 5) = 510813 14:18:37.017894 open("./test/db.opt", O_RDONLY) = -1 ENOENT (No s...uch file or directory)10813 14:18:37.018026 write(31, "\7\0\0\1\0\0\0\2\0\0\0", 11) = 1110813 14:18:37.018145 read(31, 0x1c136e0, 4) = -1 EAGAIN (Resource temp...orarily unavailable)\
Strace to observe process
www.percona.com
Tool #6: strace
Strace to see which my.cnf's are being readstrace -f mysql -h127.0.0.1 --port=29783 |& grep my.cnf
stat("/etc/my.cnf", {st_mode=S_IFREG|0644, st_size=480, ...}) = 0open("/etc/my.cnf", O_RDONLY) = 3stat("/etc/mysql/my.cnf", 0x7fff983f5810) = -1 ENOENT (No such file or directory)stat("/usr/etc/my.cnf", 0x7fff983f5810) = -1 ENOENT (No such file or directory)stat("/home/kolita/.my.cnf", {st_mode=S_IFREG|0664, st_size=189, ...}) = 0open("/home/kolita/.my.cnf", O_RDONLY) = 3
www.percona.com
perf
Tool #7:
www.percona.com
Tool #7: perf
perf top -p `pgrep -x mysqld`
Simple system-wide top-like profiler
www.percona.com
Tool #7: perf
Perf lines to replace oprofileperf record \ --all-cpus \ --call-graph \ --stat \ --pid=`pgrep -x mysqld`
perf report g flat
www.percona.com
H
Tool #7: perf
www.percona.com
netstat
Tool #8:
www.percona.com
Network statusnetstat -topan
Tool #8: netstat
www.percona.com
Network statsnetstat -s
Ip: 627568 total packets received 0 forwarded 0 incoming packets discarded 626949 incoming packets delivered 565646 requests sent out 1344 outgoing packets dropped 562 dropped because of missing routeTcp:2812 active connections openings 12 passive connection openings 9 failed connection attempts 14 connection resets received 8 connections established... <lots more...>
Tool #8: netstat
www.percona.com
ethtool
Tool #9
www.percona.com
Network interface statistics and error detailsethtool -S em1
NIC statistics: rx_packets: 0 tx_packets: 0 rx_bytes: 0 tx_bytes: 0 rx_broadcast: 0 tx_broadcast: 0 rx_multicast: 0 tx_multicast: 0 rx_errors: 0 tx_errors: 0 tx_dropped: 0 ....
Tool #9: ethtool
www.percona.com
tcpdump
Tool #10
www.percona.com
$tcpdump -XX -i eth018:52:54.859697 IP zz.domain.innetbcp.net.63897 > valh4.lell.net.ssh: . ack 232 win 16511 0x0000: 0050 569c 35a3 0019 bb1c 0c00 0800 4500 .PV.5.........E. 0x0010: 0028 042a 4000 7906 c89c 10b5 aaf6 0f9a .(.*@.y......... 0x0020: 69c4 f999 0016 57db 6e08 c712 ea2e 5010 i.....W.n.....P. 0x0030: 407f c976 0000 0000 0000 0000 @..v........18:52:54.877713 IP 10.0.0.0 > all-systems.mcast.net: igmp query v3 [max resp time 1s] 0x0000: 0050 569c 35a3 0000 0000 0000 0800 4600 .PV.5.........F. 0x0010: 0024 0000 0000 0102 3ad3 0a00 0000 e000 .$......:....... 0x0020: 0001 9404 0000 1101 ebfe 0000 0000 0300 ................ 0x0030: 0000 0000 0000 0000 0000 0000 ............
Tool #10: tcpdump
www.percona.com
- Capture packets * from an interface * from a host * to a port * of only target protocols- Filter packets- Determine traffic volumes- Read non-encrypted traffic- Generate a slow query report- ...
Tool #10: tcpdump
www.percona.com
More tools
● systemtap (full stack)
● dmesg (kernel)
● numactl (memory/cpu)
● bkltrace (storage)
● ping (network)
● dstat (storage/memory/cpu)
● sar (storage/memory/cpu)
● ip (network)
● nicstat (network)
● slabtop (memory)
● free (memory)
● pidstat (storage/memory/cpu)
● mpstat (cpu)
● uptime (load)
● df (storage)
● htop (memory/cpu)
www.percona.com
Questions
?
