Some key analysis tools of MySQL

Keywords: MySQL less SQL snapshot

Catalog

pstack

Get stack information
Problem thread positioning
Low load

mysql_pid=4522
pstack $mysql_pid>pstack.info

PT PMP sorting stack information
pt-pmp pstack.info | less

You can also directly execute Pt PMP
pt-pmp --pid 4522
as

     10 __io_getevents_0_4(libaio.so.1),LinuxAIOHandler::collect(os0file.cc:2502),LinuxAIOHandler::poll(os0file.cc:2648),os_aio_linux_handler(os0file.cc:2704),os_aio_handler(os0file.cc:2704),fil_aio_wait(fil0fil.cc:5835),io_handler_thread(srv0start.cc:311),start_thread(libpthread.so.0),clone(libc.so.6)
      3 pthread_cond_wait,wait(os0event.cc:165),os_event::wait_low(os0event.cc:165),srv_worker_thread(srv0srv.cc:2520),start_thread(libpthread.so.0),clone(libc.so.6)
      2 pthread_cond_wait,native_cond_wait(thr_cond.h:140),my_cond_wait(thr_cond.h:140),inline_mysql_cond_wait(thr_cond.h:140),Per_thread_connection_handler::block_until_new_connection(thr_cond.h:140),handle_connection(connection_handler_per_thread.cc:329),pfs_spawn_thread(pfs.cc:2190),start_thread(libpthread.so.0),clone(libc.so.6)

gdb

stack trace
Wait analysis
Invasive large

mysqld_pid 4522
gdb -p $mysqld_pid
(gdb) info thread shows all threads running
(gdb) thread 4 switch to a thread
bt display call stack
as

SELECT B.THREAD_OS_ID AS mysqld_os_thread_id,A.ID as processlist_id,A.USER,A.HOST,A.DB,A.COMMAND,A.TIME,A.STATE,LEFT(A.INFO,150) AS statement FROM information_schema.PROCESSLIST A INNER JOIN performance_schema.threads B on A.ID=B.PROCESSLIST_ID where A.id !=connection_id();

+---------------------+----------------+-------+-----------+------+---------+------+---------------------------------+----------------------------------------+
| mysqld_os_thread_id | processlist_id | USER | HOST | DB | COMMAND | TIME | STATE | statement |
+---------------------+----------------+-------+-----------+------+---------+------+---------------------------------+----------------------------------------+
| 27015 | 4 | admin | localhost | NULL | Sleep | 2597 | | NULL |
| 28252 | 6 | admin | localhost | test | Query | 1166 | Waiting for table metadata lock | alter table test.test_1 drop index idx |
+---------------------+----------------+-------+-----------+------+---------+------+---------------------------------+----------------------------------------+
(gdb) thread 4
[Switching to thread 4 (Thread 0x7f8d107f8700 (LWP 28252))]
#0 0x00007f8d3b147d12 in pthread_cond_timedwait@@GLIBC_2.3.2 () from /lib64/libpthread.so.0

bt
........
#4 MDL_wait::timed_wait (this=0x7f8ce4000958, owner=0x7f8ce40008c0, abs_timeout=0x7f8d107f37e0, set_status_on_timeout=false,
wait_state_name=) at /export/home/pb2/build/sb_0-27500212-1520171728.22/mysql-5.7.22/sql/mdl.cc:1861

  • Processlist "id 6 (mysqld thread id 28252 in os) is waiting for MDL metadata lock. Through gdb stack trace, it is found that the internal function of the connection is pthread" cond "timedwait

Be careful

  • Both pstack and gdb can get stack information. The difference is that gdb is interactive (manual exit is required), and pstack is in the form of snapshot (automatic exit for 3s)
  • After gdb is used for mysqld, the established connection can no longer execute statements, and the new connection cannot be established


strace

Viewing system call information for a process
Higher load

View system calls
strace -cp $mysqld_pid

View execution statement
mysqld_pid=4522
strace -f -F -ff -o mysqld-strace -s 1024 -p $mysqld_pid
find ./ -name "mysqld-strace" -type f -print |xargs grep -n "SELECT.FROM"

View read-write files
strace -o /tmp/strace_output.txt -T -tt -f -e trace=read,open -p "mysqld_pid"

perf

Process internal function calls
Low load

Overall consumption of mysqld internal functions
perf top -p 4522
as

Samples: 66  of event 'cpu-clock', Event count (approx.): 6520074                                                                 
Overhead  Shared Object       Symbol                                                                                              
  18.42%  mysqld              [.] sync_array_print_long_waits_low
  10.83%  [kernel]            [k] _raw_spin_unlock_irqrestore
   7.88%  libaio.so.1.0.1     [.] 0x0000000000000645
   7.30%  [kernel]            [k] finish_task_switch
   6.84%  [kernel]            [k] system_call_after_swapgs
   6.22%  [kernel]            [k] aio_read_events
   6.02%  libc-2.17.so        [.] __memset_sse2

Record all internal function calls
This command will output and record to perf.data
perf record -p 4522

Parse and view perf.data content
perf script -i perf.data>perf.log && less perf.log

Reference resources

Troubleshooting of hang problems in all MySQL operations
linux strace trace mysql execution statement (mysqld --debug)
linux debugging tools gdb, strace, pstack, pstree, lsof
Debugging a MySQL Server
What to Do If MySQL Keeps Crashing

Posted by fatmart on Mon, 11 Nov 2019 15:09:47 -0800