perf mysql_通过perf 查看mysql 堆栈

OS version：Red Hat Enterprise Linux Server release 6.3 (Santiago)

MYSQL version： 8.0.18-commercial MySQL Enterprise Server - Commercial

[root@dbmspredb308 mysql_backup]# perf record -a --call-graph -p 29052

[ perf record: Woken up 1 times to write data ]

[ perf record: Captured and wrote 0.154 MB perf.data (~6719 samples) ]

[root@dbmspredb308 mysql_backup]# perf report --call-graph --stdio

# ========

# captured on: Sat Jun 27 20:45:09 2020

# hostname : dbmspredb308

# os release : 2.6.32-279.19.1.el6_sn.62.x86_64

# perf version : 2.6.32-279.el6_sn.13.x86_64

# arch : x86_64

# nrcpus online : 8

# nrcpus avail : 8

# cpudesc : Intel Xeon E312xx (Sandy Bridge)

# cpuid : GenuineIntel,6,42,1

# total memory : 16332232 kB

# cmdline : /usr/bin/perf record -a --call-graph -p 29052

# event : name = cycles, type = 1, config = 0x0, config1 = 0x0, config2 = 0x0, excl_usr = 0, excl_kern = 0, id = { 92, 93, 94, 95, 96, 97, 98, 99, 100, 101, 102, 103,

# HEADER_CPU_TOPOLOGY info available, use -I to display

# HEADER_NUMA_TOPOLOGY info available, use -I to display

# ========

#

# Events: 790 cpu-clock

#

# Overhead Command Shared Object

# ........ ....... .................... ............................................................................................................................

#

34.56% mysqld group_replication.so [.] Certifier::garbage_collect()

|

--- Certifier::garbage_collect()

9.87% mysqld libc-2.12.so [.] malloc

|

--- malloc

8.99% mysqld libc-2.12.so [.] _int_free

|

--- _int_free

7.09% mysqld mysqld [.] Gtid_set::equals(Gtid_set const*) const

|

--- Gtid_set::equals(Gtid_set const*) const

5.57% mysqld mysqld [.] std::_Hashtable<:uuid std::pair const std::unique_ptr my_free_deleter> >, M

|

--- std::_Hashtable<:uuid std::pair const std::unique_ptr my_free_deleter> >, Malloc_allocator<:pair>

5.32% mysqld libc-2.12.so [.] _int_malloc

|

--- _int_malloc

3.92% mysqld mysqld [.] Gtid_set::is_subset(Gtid_set const*) const

|

--- Gtid_set::is_subset(Gtid_set const*) const

2.41% mysqld mysqld [.] std::_Hash_bytes(void const*, unsigned long, unsigned long)

|

--- std::_Hash_bytes(void const*, unsigned long, unsigned long)

2.03% mysqld libc-2.12.so [.] memcpy

|

--- memcpy

1.65% mysqld mysqld [.] Gtid_set::is_interval_subset(Gtid_set::Const_interval_iterator*, Gtid_set::Const_interval_iterator*)

|

--- Gtid_set::is_interval_subset(Gtid_set::Const_interval_iterator*, Gtid_set::Const_interval_iterator*)

1.52% mysqld libpthread-2.12.so [.] pthread_cond_timedwait@@GLIBC_2.3.2

|

--- pthread_cond_timedwait@@GLIBC_2.3.2

1.39% mysqld mysqld [.] Gtid_set::sidno_equals(int, Gtid_set const*, int) const

|

--- Gtid_set::sidno_equals(int, Gtid_set const*, int) const

1.14% mysqld libstdc++.so.6.0.13 [.] operator new(unsigned long)

|

--- operator new(unsigned long)

1.14% mysqld libstdc++.so.6.0.13 [.] 0x9ce6a

|

--- 0x7fc8a412be6a

|

--- 0x7fc8a412be04

|

--- 0x7fc8a412bdf1

|

--- 0x7fc8a412bde7

|

--- 0x7fc8a412bdb8

1.01% mysqld mysqld [.] sync_array_print_long_waits_low(sync_array_t*, unsigned long*, void const**, unsigned long*)

|

--- sync_array_print_long_waits_low(sync_array_t*, unsigned long*, void const**, unsigned long*)

0.89% mysqld libstdc++.so.6.0.13 [.] std::basic_string, std::allocator >::basic_string(char const*, unsigned long, std::al

|

--- std::basic_string, std::allocator >::basic_string(char const*, unsigned long, std::allocator const&)

0.63% mysqld libc-2.12.so [.] free

|

--- free

0.51% mysqld libstdc++.so.6.0.13 [.] _ZNSs4_Rep9_S_createEmmRKSaIcE@plt

|

--- _ZNSs4_Rep9_S_createEmmRKSaIcE@plt

0.51% mysqld libstdc++.so.6.0.13 [.] std::string::_Rep::_S_create(unsigned long, unsigned long, std::allocator const&)

|

--- std::string::_Rep::_S_create(unsigned long, unsigned long, std::allocator const&)

0.51% mysqld librt-2.12.so [.] clock_gettime

|

--- clock_gettime

0.51% mysqld libcrypto.so.1.1 [.] bn_mul_add_words

|

--- bn_mul_add_words

0.38% mysqld libpthread-2.12.so [.] pthread_mutex_unlock

|

--- pthread_mutex_unlock

0.38% mysqld [kernel.kallsyms] [k] iowrite16

|

--- iowrite16

__libc_send

|

--100.00%-- task_write

flush_srv_buf

sender_task

task_loop

xcom_taskmain2

xcom_taskmain_startup(void*)

start_thread

0.25% mysqld mysqld [.] log_checkpointer(log_t*)

|

--- log_checkpointer(log_t*)

0.25% mysqld mysqld [.] log_closer(log_t*)

|

--- log_closer(log_t*)

0.25% mysqld mysqld [.] buf_pool_get_oldest_modification_approx()

|

--- buf_pool_get_oldest_modification_approx()

0.25% mysqld libstdc++.so.6.0.13 [.] _ZdlPv@plt

|

--- _ZdlPv@plt

0.25% mysqld group_replication.so [.] _ZNK8Gtid_set9is_subsetEPKS_@plt

|

--- _ZNK8Gtid_set9is_subsetEPKS_@plt

0.25% mysqld group_replication.so [.] _ZNK8Gtid_set6equalsEPKS_@plt

|

--- _ZNK8Gtid_set6equalsEPKS_@plt

0.25% mysqld [kernel.kallsyms] [k] sys_clock_gettime

|

--- sys_clock_gettime

0x7fffa2cbea01

0.25% mysqld [kernel.kallsyms] [k] __audit_syscall_exit

|

--- __audit_syscall_exit

|

|--50.00%-- pthread_cond_broadcast@@GLIBC_2.3.2

|

--50.00%-- pthread_cond_timedwait@@GLIBC_2.3.2

os_event::wait_time_low(unsigned long, long)

log_checkpointer(log_t*)

_ZNSt6thread11_State_implINS_8_InvokerISt5tupleIJ8RunnablePFvP5log_tES5_EEEEE6_M_runEv

execute_native_thread_routine

0.25% mysqld [kernel.kallsyms] [k] do_sys_poll

|

--- do_sys_poll

__poll

task_loop

xcom_taskmain2

xcom_taskmain_startup(void*)

start_thread

0.25% mysqld [kernel.kallsyms] [k] tcp_poll

|

--- tcp_poll

__poll

task_loop

xcom_taskmain2

xcom_taskmain_startup(void*)

start_thread

0.25% mysqld [kernel.kallsyms] [k] _spin_lock

|

--- _spin_lock

pthread_cond_timedwait@@GLIBC_2.3.2

|

--100.00%-- os_event::wait_time_low(unsigned long, long)

log_checkpointer(log_t*)

_ZNSt6thread11_State_implINS_8_InvokerISt5tupleIJ8RunnablePFvP5log_tES5_EEEEE6_M_runEv

execute_native_thread_routine

0.13% mysqld mysqld [.] pthread_mutex_unlock@plt

|

--- pthread_mutex_unlock@plt

0.13% mysqld mysqld [.] Gtid_set::~Gtid_set()

|

--- Gtid_set::~Gtid_set()

0.13% mysqld mysqld [.] Rpl_applier_reader::read_next_event()

|

--- Rpl_applier_reader::read_next_event()

0.13% mysqld mysqld [.] PolicyMutex >::enter(unsigned int, unsigned int, char const*, unsigned int)

|

--- PolicyMutex >::enter(unsigned int, unsigned int, char const*, unsigned int)

0.13% mysqld mysqld [.] log_writer(log_t*)

|

--- log_writer(log_t*)

0.13% mysqld mysqld [.] os_event::timed_wait(timespec const*)

|

--- os_event::timed_wait(timespec const*)

0.13% mysqld mysqld [.] os_event::get_wait_timelimit(unsigned long)

|

--- os_event::get_wait_timelimit(unsigned long)

0.13% mysqld mysqld [.] os_event::wait_time_low(unsigned long, long)

|

--- os_event::wait_time_low(unsigned long, long)

0.13% mysqld mysqld [.] Clone_persist_gtid::periodic_write()

|

--- Clone_persist_gtid::periodic_write()

0.13% mysqld libstdc++.so.6.0.13 [.] _Znwm@plt

|

--- _Znwm@plt

0.13% mysqld libstdc++.so.6.0.13 [.] std::string::_Rep::_M_destroy(std::allocator const&)

|

--- std::string::_Rep::_M_destroy(std::allocator const&)

0.13% mysqld libstdc++.so.6.0.13 [.] std::string::_M_mutate(unsigned long, unsigned long, unsigned long)

|

--- std::string::_M_mutate(unsigned long, unsigned long, unsigned long)

0.13% mysqld libpthread-2.12.so [.] pthread_once

|

--- pthread_once

0.13% mysqld libcrypto.so.1.1 [.] bn_mul_comba8

|

--- bn_mul_comba8

0.13% mysqld libcrypto.so.1.1 [.] bn_sqr_comba8

|

--- bn_sqr_comba8

0.13% mysqld libcrypto.so.1.1 [.] MOD_EXP_CTIME_COPY_FROM_PREBUF

|

--- MOD_EXP_CTIME_COPY_FROM_PREBUF

0.13% mysqld libc-2.12.so [.] __memset_sse2

|

--- __memset_sse2

0.13% mysqld libc-2.12.so [.] __poll

|

--- __poll

0.13% mysqld libc-2.12.so [.] __libc_disable_asynccancel

|

--- __libc_disable_asynccancel

0.13% mysqld libc-2.12.so [.] xdr_array

|

--- xdr_array

0.13% mysqld libc-2.12.so [.] __memcmp_sse4_1

|

--- __memcmp_sse4_1

0.13% mysqld group_replication.so [.] Gcs_operations::send_message(Plugin_gcs_message const&, bool)

|

--- Gcs_operations::send_message(Plugin_gcs_message const&, bool)

0.13% mysqld group_replication.so [.] Parameterized_notification::operator()()

|

--- Parameterized_notification::operator()()

0.13% mysqld group_replication.so [.] init_ballot

|

--- init_ballot

0.13% mysqld group_replication.so [.] cache_manager_task

|

--- cache_manager_task

0.13% mysqld group_replication.so [.] buffered_read_msg

|

--- buffered_read_msg

0.13% mysqld group_replication.so [.] link_first

|

--- link_first

0.13% mysqld group_replication.so [.] link_precede

|

--- link_precede

0.13% mysqld group_replication.so [.] xdr_client_reply_code

|

--- xdr_client_reply_code

0.13% mysqld group_replication.so [.] psi_report_mem_alloc

|

--- psi_report_mem_alloc

0.13% mysqld [kernel.kallsyms] [k] system_call_after_swapgs

|

--- system_call_after_swapgs

pthread_cond_timedwait@@GLIBC_2.3.2

0.13% mysqld [kernel.kallsyms] [k] local_bh_enable

|

--- local_bh_enable

__libc_recv

0.13% mysqld [kernel.kallsyms] [k] ktime_get_ts

|

--- ktime_get_ts

0x7fffa2cbea01

0.13% mysqld [kernel.kallsyms] [k] futex_wait

|

--- futex_wait

pthread_cond_timedwait@@GLIBC_2.3.2

os_event::wait_time_low(unsigned long, long)

log_checkpointer(log_t*)

_ZNSt6thread11_State_implINS_8_InvokerISt5tupleIJ8RunnablePFvP5log_tES5_EEEEE6_M_runEv

execute_native_thread_routine

0.13% mysqld [kernel.kallsyms] [k] sys_futex

|

--- sys_futex

pthread_cond_timedwait@@GLIBC_2.3.2

os_event::wait_time_low(unsigned long, long)

Clone_persist_gtid::periodic_write()

_ZNSt6thread11_State_implINS_8_InvokerISt5tupleIJ8RunnablePFvP18Clone_persist_gtidES5_EEEEE6_M_runEv

execute_native_thread_routine

0.13% mysqld [kernel.kallsyms] [k] __rcu_process_callbacks

|

--- __rcu_process_callbacks

pthread_cond_timedwait@@GLIBC_2.3.2

os_event::wait_time_low(unsigned long, long)

log_checkpointer(log_t*)

_ZNSt6thread11_State_implINS_8_InvokerISt5tupleIJ8RunnablePFvP5log_tES5_EEEEE6_M_runEv

execute_native_thread_routine

0.13% mysqld [kernel.kallsyms] [k] fget_light

|

--- fget_light

__poll

task_loop

xcom_taskmain2

xcom_taskmain_startup(void*)

start_thread

0.13% mysqld [kernel.kallsyms] [k] plist_add

|

--- plist_add

pthread_cond_timedwait@@GLIBC_2.3.2

0.13% mysqld [kernel.kallsyms] [k] lock_sock_nested

|

--- lock_sock_nested

__libc_recv

0.13% mysqld [kernel.kallsyms] [k] tcp_ack

|

--- tcp_ack

__libc_send

socket_write

xcom_input_signal

Gcs_xcom_proxy_impl::xcom_input_try_push(app_data*)

Gcs_xcom_proxy_impl::xcom_client_send_data(unsigned long long, char*)

Gcs_xcom_communication::do_send_message(Gcs_message const&, unsigned long long*, Cargo_type)

Gcs_xcom_communication::send_message(Gcs_message const&)

Gcs_operations::send_message(Plugin_gcs_message const&, bool)

Pipeline_stats_member_collector::send_stats_member_message(Flow_control_mode)

Flow_control_module::flow_control_step(Pipeline_stats_member_collector*)

Certifier_broadcast_thread::dispatcher()

launch_broadcast_thread(void*)

start_thread

0.13% mysqld [kernel.kallsyms] [k] tcp_event_new_data_sent

|

--- tcp_event_new_data_sent

__libc_send

task_write

flush_srv_buf

sender_task

task_loop

xcom_taskmain2

xcom_taskmain_startup(void*)

start_thread

0.13% mysqld [ip_tables] [k] ipt_do_table

|

--- ipt_do_table

__libc_send

net_write_packet(NET*, unsigned char const*, unsigned long)

net_flush(NET*)

send_server_handshake_packet(MPVIO_EXT*, char const*, unsigned int)

server_mpvio_write_packet

caching_sha2_password_authenticate(MYSQL_PLUGIN_VIO*, MYSQL_SERVER_AUTH_INFO*)

do_auth_once(THD*, MYSQL_LEX_CSTRING const&, MPVIO_EXT*)

acl_authenticate(THD*, enum_server_command)

check_connection(THD*)

thd_prepare_connection(THD*)

handle_connection

pfs_spawn_thread

start_thread

#

# (For a higher level overview, try: perf report --sort comm,dso)

#