Performance regression with 5.5 around triggers / functions and replication

MySQL & MariaDB Other MySQL® Questions
1

Hello

I have noticed a performance regression running Percona 5.5 over Percona 5.1 with the use of triggers and function and replication.

We have a replicated configuration and we have recently upgraded from Percona 5.1 5.1.45-89.lenny.52-log under Lenny to 5.5.12-55 under RHEL6.1

The master server is running 5.5 under rhel6 and we have two slaves

  1. running 5.1 under lenny with an extra schema and triggers and functions that are fired upon the slave SQL thread [to generate messages in the new schema]
  2. running 5.5 under rhel6 with an extra schema and triggers and functions that are fired upon the slave SQL thread [to generate messages in the new schema]

The schema between the two replicas is the same.

We noticed a 50% performance hit when looking at the two. I have tweaked the 5.5 box as much as i can though I cannot get any decent write performance from it. The box is spending most of its time in user space.

Comparing the pmp output of the two boxes:

Percona 5.5:

/tmp# cat pmp.out.with-triggers.percona55
1501
600 ??,??,??,??,start_thread,clone
298 pthread_cond_wait@@GLIBC_2.3.2 ,one_thread_per_connection_end(THD*,do_handle_one_connectio n(THD*),handle_one_connection,pfs_spawn_thread,start_thread, clone
180 pthread_cond_timedwait@@GLIBC_2.3.2,??,??,start_thread,clone
177 select,??,??,start_thread,clone
60 sigwait,signal_hand,pfs_spawn_thread,start_thread,clone
60 poll,handle_connections_sockets(),mysqld_main(int,__libc_st art_main,_start
56 read,vio_read_buff,??,my_net_read,cli_safe_read,handle_slave _io,pfs_spawn_thread,start_thread,clone
18 cleanup_items(Item*),sp_head::execute(THD*,sp_head::execute function(THD*,Item_func_sp::execute_impl(THD*),Item_func_s p::execute(),Item_func_sp::val_int(),Item::val_bool(),Item_c ond_and::val_int(),Item::val_bool(),sp_instr_jump_if_not::ex ec_core(THD*,sp_lex_keeper::reset_lex_and_exec_core(THD*,s p_head::execute(THD*,sp_head::execute_trigger(THD*,Table_t riggers_list::process_triggers(THD*,mysql_update(THD*,mysq l_execute_command(THD*),mysql_parse(THD*,Query_log_event::d o_apply_event(Relay_log_info,apply_event_and_update_pos(Log event*,??,handle_slave_sql,pfs_spawn_thread,start_thread,cl one
9 pread64,??,??,??,??,??,??,??,??,??,??,??,handler::read_range _first(st_key_range,handler::read_multi_range_first(st_key_m ulti_range**,QUICK_RANGE_SELECT::get_next(),??,mysql_update (THD*,mysql_execute_command(THD*),mysql_parse(THD*,Query_l og_event::do_apply_event(Relay_log_info,apply_event_and_upda te_pos(Log_event*,??,handle_slave_sql,pfs_spawn_thread,star t_thread,clone
9 cleanup_items(Item*),sp_head::execute(THD*,sp_head::execute _function(THD*,Item_func_sp::execute_impl(THD*),Item_func_s p::execute(),Item_func_sp::val_int(),Item::val_bool(),sp_ins tr_jump_if_not::exec_core(THD*,sp_lex_keeper::reset_lex_and _exec_core(THD*,sp_head::execute(THD*,sp_head::execute_tri gger(THD*,Table_triggers_list::process_triggers(THD*,write record(THD*,mysql_insert(THD*,mysql_execute_command(THD*) ,mysql_parse(THD*,Query_log_event::do_apply_event(Relay_log info,apply_event_and_update_pos(Log_event*,??,handle_slave sql,pfs_spawn_thread,start_thread,clone
8 Item_basic_constant::cleanup(),cleanup_items(Item*),sp_head: :execute(THD*,sp_head::execute_function(THD*,Item_func_sp: :execute_impl(THD*),Item_func_sp::execute(),Item_func_sp::va l_int(),Item::val_bool(),Item_cond_and::val_int(),Item::val bool(),sp_instr_jump_if_not::exec_core(THD*,sp_lex_keeper:: reset_lex_and_exec_core(THD*,sp_head::execute(THD*,sp_head ::execute_trigger(THD*,Table_triggers_list::process_trigger s(THD*,mysql_update(THD*,mysql_execute_command(THD*),mysql parse(THD*,Query_log_event::do_apply_event(Relay_log_info, apply_event_and_update_pos(Log_event*,??,handle_slave_sql,p fs_spawn_thread,start_thread,clone
3 pread64,??,??,??,??,??,??,??,??,??,??,??,??,??,??,??,start_t hread,clone
3 pread64,??,??,??,??,??,??,??,??,??,??,??,handler::read_range first(st_key_range,handler::read_multi_range_first(st_key_m ulti_range**,QUICK_RANGE_SELECT::get_next(),??,mysql_delete (THD*,mysql_execute_command(THD*),mysql_parse(THD*,Query_l og_event::do_apply_event(Relay_log_info,apply_event_and_upda te_pos(Log_event*,??,handle_slave_sql,pfs_spawn_thread,star t_thread,clone
3 Item_basic_constant::cleanup(),cleanup_items(Item*),sp_head: :execute(THD*,sp_head::execute_function(THD*,Item_func_sp: :execute_impl(THD*),Item_func_sp::execute(),Item_func_sp::va l_int(),Item::val_bool(),sp_instr_jump_if_not::exec_core(THD ,sp_lex_keeper::reset_lex_and_exec_core(THD,sp_head::exe cute(THD*,sp_head::execute_trigger(THD*,Table_triggers_lis t::process_triggers(THD*,write_record(THD*,mysql_insert(TH D*,mysql_execute_command(THD*),mysql_parse(THD*,Query_log event::do_apply_event(Relay_log_info,apply_event_and_update pos(Log_event*,??,handle_slave_sql,pfs_spawn_thread,start_t hread,clone
3 cleanup_items(Item*),sp_head::execute(THD*,sp_head::execute function(THD*,Item_func_sp::execute_impl(THD*),Item_func_s p::execute(),Item_func_sp::val_str(String*),Item::save_in_fi eld(Field*,sp_eval_expr(THD*,sp_rcontext::set_variable(THD ,sp_head::execute_procedure(THD,mysql_execute_command(TH D*),sp_instr_stmt::exec_core(THD*,sp_lex_keeper::reset_lex and_exec_core(THD*,sp_instr_stmt::execute(THD*,sp_head::ex ecute(THD*,sp_head::execute_trigger(THD*,Table_triggers_li st::process_triggers(THD*,write_record(THD*,mysql_insert(T HD*,mysql_execute_command(THD*),mysql_parse(THD*,Query_log event::do_apply_event(Relay_log_info,apply_event_and_update pos(Log_event*,??,handle_slave_sql,pfs_spawn_thread,start thread,clone
2 read,??,my_net_read,do_command(THD*),do_handle_one_connectio n(THD*),handle_one_connection,pfs_spawn_thread,start_thread, clone
2 pread64,??,??,??,??,??,??,??,??,??,??,??,??,??,handler::ha_w rite_row(unsigned,write_record(THD*,mysql_insert(THD*,mysq l_execute_command(THD*),mysql_parse(THD*,Query_log_event::d o_apply_event(Relay_log_info,apply_event_and_update_pos(Log event*,??,handle_slave_sql,pfs_spawn_thread,start_thread,cl one
1 write,my_write,my_b_flush_io_cache,MYSQL_BIN_LOG::flush_and sync(bool*),MYSQL_BIN_LOG::appendv(char,??,handle_slave_io,p fs_spawn_thread,start_thread,clone
1 write,my_write,my_b_flush_io_cache,flush_master_info(Master info*,handle_slave_io,pfs_spawn_thread,start_thread,clone
1 ??,sp_instr_stmt::execute(THD*,sp_head::execute(THD*,sp_he ad::execute_function(THD*,Item_func_sp::execute_impl(THD*), Item_func_sp::execute(),Item_func_sp::val_str(String*),Item: :save_in_field(Field*,sp_eval_expr(THD*,sp_rcontext::set_v ariable(THD*,sp_head::execute_procedure(THD*,mysql_execute command(THD*),sp_instr_stmt::exec_core(THD*,sp_lex_keeper: :reset_lex_and_exec_core(THD*,sp_instr_stmt::execute(THD*, sp_head::execute(THD*,sp_head::execute_trigger(THD*,Table triggers_list::process_triggers(THD*,write_record(THD*,mys ql_insert(THD*,mysql_execute_command(THD*),mysql_parse(THD* ,Query_log_event::do_apply_event(Relay_log_info,apply_event _and_update_pos(Log_event*,??,handle_slave_sql,pfs_spawn_th read,start_thread,clone
1 __printf_fp,vfprintf,__vsprintf_chk,__sprintf_chk,flush_mast er_info(Master_info*,handle_slave_io,pfs_spawn_thread,start _thread,clone
1 poll,my_connect,mysql_real_connect,mysql_reconnect,??,??,han dle_slave_io,pfs_spawn_thread,start_thread,clone
1 memcpy,??,??,??,handler::read_range_first(st_key_range,handl er::read_multi_range_first(st_key_multi_range**,QUICK_RANGE _SELECT::get_next(),??,mysql_update(THD*,mysql_execute_comm and(THD*),mysql_parse(THD*,Query_log_event::do_apply_event( Relay_log_info,apply_event_and_update_pos(Log_event*,??,han dle_slave_sql,pfs_spawn_thread,start_thread,clone
1 Item::is_splocal(),??,sp_instr_stmt::execute(THD*,sp_head:: execute(THD*,sp_head::execute_function(THD*,Item_func_sp:: execute_impl(THD*),Item_func_sp::execute(),Item_func_sp::val _str(String*),Item::save_in_field(Field*,sp_eval_expr(THD*, ,sp_rcontext::set_variable(THD*,sp_head::execute_procedure( THD*,mysql_execute_command(THD*),sp_instr_stmt::exec_core(T HD*,sp_lex_keeper::reset_lex_and_exec_core(THD*,sp_instr_s tmt::execute(THD*,sp_head::execute(THD*,sp_head::execute_t rigger(THD*,Table_triggers_list::process_triggers(THD*,wri te_record(THD*,mysql_insert(THD*,mysql_execute_command(THD ),mysql_parse(THD,Query_log_event::do_apply_event(Relay_l og_info,apply_event_and_update_pos(Log_event*,??,handle_sla ve_sql,pfs_spawn_thread,start_thread,clone
1 ??,??,??,??,??,??,??,??,??,??,handler::ha_write_row(unsigned ,write_record(THD*,mysql_insert(THD*,mysql_execute_command (THD*),mysql_parse(THD*,Query_log_event::do_apply_event(Rel ay_log_info,apply_event_and_update_pos(Log_event*,??,handle _slave_sql,pfs_spawn_thread,start_thread,clone
1 alloc_root,sp_rcontext::init(THD*),sp_head::execute_function (THD*,Item_func_sp::execute_impl(THD*),Item_func_sp::execut e(),Item_func_sp::val_int(),Item::val_bool(),Item_cond_and:: val_int(),Item::val_bool(),sp_instr_jump_if_not::exec_core(T HD*,sp_lex_keeper::reset_lex_and_exec_core(THD*,sp_head::e xecute(THD*,sp_head::execute_trigger(THD*,Table_triggers_l ist::process_triggers(THD*,mysql_update(THD*,mysql_execute _command(THD*),mysql_parse(THD*,Query_log_event::do_apply_e vent(Relay_log_info,apply_event_and_update_pos(Log_event*,? ?,handle_slave_sql,pfs_spawn_thread,start_thread,clone

/tmp# cat pmp.out.with-triggers.percona51
6001
3327 pthread_cond_wait@@GLIBC_2.3.2 ,one_thread_per_connection_end,handle_one_connection,start_t hread,clone,??
2019 pthread_cond_wait@@GLIBC_2.3.2,??,??,??,??,start_thread,clone,??
193 select,??,??,start_thread,clone,??
93 read,??,my_net_read,do_command,handle_one_connection,start_t hread,clone,??
60 select,handle_connections_sockets,main,select
60 do_sigwait,sigwait,signal_hand,start_thread,clone,??
59 read,vio_read_buff,??,my_net_read,cli_safe_read,handle_slave io,start_thread,clone,??
15 pthread_cond_wait@@GLIBC_2.3.2,??,??,??,??,??,??,??,??,??,??,??,start_thread,clone,??
13 pread64,??,??,??,??,??,??,??,??,??,handler::read_range_first ,handler::read_multi_range_first,QUICK_RANGE_SELECT::get_nex t,??,mysql_update,mysql_execute_command,mysql_parse,Query_lo g_event::do_apply_event,apply_event_and_update_pos,handle_sl ave_sql,start_thread,clone,??
12 pread64,??,??,??,??,??,??,??,??,??,handler::read_range_first ,handler::read_multi_range_first,QUICK_RANGE_SELECT::get_nex t,??,mysql_delete,mysql_execute_command,mysql_parse,Query_lo g_event::do_apply_event,apply_event_and_update_pos,handle_sl ave_sql,start_thread,clone,??
12 pread64,??,??,??,??,??,??,??,??,??,??,??,??,handler::ha_dele te_row,mysql_delete,mysql_execute_command,mysql_parse,Query log_event::do_apply_event,apply_event_and_update_pos,handle_ slave_sql,start_thread,clone,??
11 pwrite64,??,??,??,??,??,start_thread,clone,??
7 pthread_cond_wait@@GLIBC_2.3.2,??,??,??,??,??,start_thread,clone,??
7 pread64,??,??,??,??,??,??,??,??,??,??,??,??,??,??,??,start_t hread,clone,??
7 fsync,??,??,??,??,??,start_thread,clone,??
5 pread64,??,??,??,??,??,start_thread,clone,??
5 pread64,??,??,??,??,??,??,??,??,??,??,??,handler::ha_write_r ow,write_record,mysql_insert,mysql_execute_command,mysql_par se,Query_log_event::do_apply_event,apply_event_and_update_po s,handle_slave_sql,start_thread,clone,??
4 pwrite64,??,??,??,??,??,??,start_thread,clone,??
3 pthread_cond_wait@@GLIBC_2.3.2,??,??,??,??,??,??,??,??,??,??,start_thread,clone,??
3 pread64,??,??,??,??,??,??,??,??,??,??,??,??,handler::ha_upda te_row,mysql_update,mysql_execute_command,mysql_parse,Query_ log_event::do_apply_event,apply_event_and_update_pos,handle_ slave_sql,start_thread,clone,??
2 pthread_cond_wait@@GLIBC_2.3.2,??,??,??,??,??,??,??,??,start_thread,clone,??
2 pthread_cond_wait@@GLIBC_2.3.2 ,??,??,??,??,??,??,??,??,handler::ha_write_row,write_record, mysql_insert,mysql_execute_command,mysql_parse,Query_log_eve nt::do_apply_event,apply_event_and_update_pos,handle_slave_s ql,start_thread,clone,??
2 pthread_cond_wait@@GLIBC_2.3.2 ,??,??,??,??,??,??,??,??,??,??,??,??,??,handler::ha_update_r ow,mysql_update,mysql_execute_command,mysql_parse,Query_log_ event::do_apply_event,apply_event_and_update_pos,handle_slav e_sql,start_thread,clone,??
2 pread64,??,??,??,??,??,??,??,??,??,??,??,??,??,??,start_thre ad,clone,??
2 pread64,??,??,??,??,??,??,??,??,??,??,??,??,handler::ha_writ e_row,write_record,mysql_insert,mysql_execute_command,mysql_ parse,Query_log_event::do_apply_event,apply_event_and_update pos,handle_slave_sql,start_thread,clone,??
2 fsync,??,??,??,??,start_thread,clone,??
1 write,my_write,my_b_flush_io_cache,flush_master_info,handle slave_io,start_thread,clone,??
1 ??,??,start_thread,clone,??
1 ??,??,??,??,start_thread,clone,??
1 start
1 pthread_mutex_trylock,my_pthread_fastmutex_lock,acl_getroot no_password,Security_context::change_security_context,sp_hea d::execute_trigger,Table_triggers_list::process_triggers,mys ql_update,mysql_execute_command,mysql_parse,Query_log_event: :do_apply_event,apply_event_and_update_pos,handle_slave_sql, start_thread,clone,??
1 pthread_cond_wait@@GLIBC_2.3.2,??,??,??,??,??,??,??,??,??,start_thread,clone,??
1 pthread_cond_wait@@GLIBC_2.3.2 ,??,??,??,??,??,??,handler::read_range_first,handler::read_m ulti_range_first,QUICK_RANGE_SELECT::get_next,??,mysql_updat e,mysql_execute_command,mysql_parse,Query_log_event::do_appl y_event,apply_event_and_update_pos,handle_slave_sql,start_th read,clone,??
1 pthread_cond_wait@@GLIBC_2.3.2 ,??,??,??,??,??,??,??,??,handler::ha_update_row,mysql_update ,mysql_execute_command,mysql_parse,Query_log_event::do_apply event,apply_event_and_update_pos,handle_slave_sql,start_thr ead,clone,??
1 pthread_cond_wait@@GLIBC_2.3.2 ,??,??,??,??,??,??,??,??,??,handler::ha_delete_row,mysql_del ete,mysql_execute_command,mysql_parse,Query_log_event::do_ap ply_event,apply_event_and_update_pos,handle_slave_sql,start thread,clone,??
1 pthread_cond_wait@@GLIBC_2.3.2 ,??,??,??,??,??,??,??,??,??,??,??,handler::ha_delete_row,mys ql_delete,mysql_execute_command,mysql_parse,Query_log_event: :do_apply_event,apply_event_and_update_pos,handle_slave_sql, start_thread,clone,??
1 pread64,??,??,??,??,??,??,??,??,??,??,??,??,??,??,handler::r ead_multi_range_next,QUICK_RANGE_SELECT::get_next,??,mysql_d elete,mysql_execute_command,mysql_parse,Query_log_event::do_ apply_event,apply_event_and_update_pos,handle_slave_sql,star t_thread,clone,??
1 open,my_open,load_db_opt,load_db_opt_by_name,Query_log_event ::do_apply_event,apply_event_and_update_pos,handle_slave_sql ,start_thread,clone,??
1 ??,??,??,??,??,??,??,??,handler::ha_write_row,write_record,m ysql_insert,mysql_execute_command,mysql_parse,Query_log_even t::do_apply_event,apply_event_and_update_pos,handle_slave_sq l,start_thread,clone,??

2

What I have noticed is that when I do not have any triggers on the RHEL6 percona 5.5 replica the performance is amazing - really high write IO and output is:

/tmp# cat pmp.out.without-triggers.percona55
1501
601 ??,??,??,??,start_thread,clone
297 pthread_cond_wait@@GLIBC_2.3.2 ,one_thread_per_connection_end(THD*,do_handle_one_connectio n(THD*),handle_one_connection,pfs_spawn_thread,start_thread, clone
180 pthread_cond_timedwait@@GLIBC_2.3.2,??,??,start_thread,clone
156 select,??,??,start_thread,clone
60 sigwait,signal_hand,pfs_spawn_thread,start_thread,clone
60 poll,handle_connections_sockets(),mysqld_main(int,__libc_st art_main,_start
59 read,vio_read_buff,??,my_net_read,cli_safe_read,handle_slave _io,pfs_spawn_thread,start_thread,clone
20 pread64,??,??,??,??,??,??,??,??,??,??,??,handler::read_range _first(st_key_range,handler::read_multi_range_first(st_key_m ulti_range**,QUICK_RANGE_SELECT::get_next(),??,mysql_update (THD*,mysql_execute_command(THD*),mysql_parse(THD*,Query_l og_event::do_apply_event(Relay_log_info,apply_event_and_upda te_pos(Log_event*,??,handle_slave_sql,pfs_spawn_thread,star t_thread,clone
14 pread64,??,??,??,??,??,??,??,??,??,??,??,handler::read_range first(st_key_range,handler::read_multi_range_first(st_key_m ulti_range**,QUICK_RANGE_SELECT::get_next(),??,mysql_delete (THD*,mysql_execute_command(THD*),mysql_parse(THD*,Query_l og_event::do_apply_event(Relay_log_info,apply_event_and_upda te_pos(Log_event*,??,handle_slave_sql,pfs_spawn_thread,star t_thread,clone
12 pread64,??,??,??,??,??,??,??,??,??,??,??,??,??,??,??,start_t hread,clone
8 pread64,??,??,??,??,??,??,??,??,??,??,??,??,??,handler::ha_w rite_row(unsigned,write_record(THD*,mysql_insert(THD*,mysq l_execute_command(THD*),mysql_parse(THD*,Query_log_event::d o_apply_event(Relay_log_info,apply_event_and_update_pos(Log event*,??,handle_slave_sql,pfs_spawn_thread,start_thread,cl one
6 pread64,??,??,??,??,??,??,??,??,??,??,??,??,??,??,??,??,star t_thread,clone
3 read,??,my_net_read,do_command(THD*),do_handle_one_connectio n(THD*),handle_one_connection,pfs_spawn_thread,start_thread, clone
3 pread64,??,??,??,??,??,??,??,??,??,??,??,??,??,??,handler::h a_write_row(unsigned,write_record(THD*,mysql_insert(THD*,m ysql_execute_command(THD*),mysql_parse(THD*,Query_log_event ::do_apply_event(Relay_log_info,apply_event_and_update_pos(L og_event*,??,handle_slave_sql,pfs_spawn_thread,start_thread ,clone
2 pthread_cond_wait@@GLIBC_2.3.2,??,??,??,??,??,??,??,??,??,??,start_thread,clone
2 pthread_cond_wait@@GLIBC_2.3.2 ,??,??,??,??,??,??,handler::read_range_first(st_key_range,ha ndler::read_multi_range_first(st_key_multi_range**,QUICK_RA NGE_SELECT::get_next(),??,mysql_update(THD*,mysql_execute_c ommand(THD*),mysql_parse(THD*,Query_log_event::do_apply_eve nt(Relay_log_info,apply_event_and_update_pos(Log_event*,??, handle_slave_sql,pfs_spawn_thread,start_thread,clone
2 pthread_cond_wait@@GLIBC_2.3.2 ,??,??,??,??,??,??,??,??,??,handler::ha_update_row(unsigned, mysql_update(THD*,mysql_execute_command(THD*),mysql_parse(T HD*,Query_log_event::do_apply_event(Relay_log_info,apply_ev ent_and_update_pos(Log_event*,??,handle_slave_sql,pfs_spawn _thread,start_thread,clone
2 pread64,??,??,??,??,??,??,??,??,??,??,??,??,??,??,??,??,??,s tart_thread,clone
2 MYSQLparse(void*),parse_sql(THD*,mysql_parse(THD*,Query_lo g_event::do_apply_event(Relay_log_info,apply_event_and_updat e_pos(Log_event*,??,handle_slave_sql,pfs_spawn_thread,start _thread,clone
1 ??,??,??,??,??,??,??,??,??,??,??,??,start_thread,clone
1 pwrite64,??,??,??,??,??,??,??,??,??,??,??,handler::ha_update _row(unsigned,mysql_update(THD*,mysql_execute_command(THD*) ,mysql_parse(THD*,Query_log_event::do_apply_event(Relay_log _info,apply_event_and_update_pos(Log_event*,??,handle_slave _sql,pfs_spawn_thread,start_thread,clone
1 pread64,??,??,??,??,??,??,??,??,??,??,??,??,handler::read_ra nge_first(st_key_range,handler::read_multi_range_first(st_ke y_multi_range**,QUICK_RANGE_SELECT::get_next(),??,mysql_upd ate(THD*,mysql_execute_command(THD*),mysql_parse(THD*,Quer y_log_event::do_apply_event(Relay_log_info,apply_event_and_u pdate_pos(Log_event*,??,handle_slave_sql,pfs_spawn_thread,s tart_thread,clone
1 pread64,??,??,??,??,??,??,??,??,??,??,??,??,??,??,??,handler ::ha_update_row(unsigned,mysql_update(THD*,mysql_execute_co mmand(THD*),mysql_parse(THD*,Query_log_event::do_apply_even t(Relay_log_info,apply_event_and_update_pos(Log_event*,??,h andle_slave_sql,pfs_spawn_thread,start_thread,clone
1 pread64,??,??,??,??,??,??,??,??,??,??,??,??,??,??,??,??,hand ler::ha_update_row(unsigned,mysql_update(THD*,mysql_execute command(THD*),mysql_parse(THD*,Query_log_event::do_apply_e vent(Relay_log_info,apply_event_and_update_pos(Log_event*,? ?,handle_slave_sql,pfs_spawn_thread,start_thread,clone
1 my_timer_cycles,get_timer_value(enum_timer_name),??,??,??,?? ,??,??,??,handler::ha_write_row(unsigned,write_record(THD*, mysql_insert(THD*,mysql_execute_command(THD*),mysql_parse(T HD*,Query_log_event::do_apply_event(Relay_log_info,apply_ev ent_and_update_pos(Log_event*,??,handle_slave_sql,pfs_spawn thread,start_thread,clone
1 insert_events_waits_history_long(PFS_events_waits*),??,load db_opt(THD*,load_db_opt_by_name(THD*,Query_log_event::do_a pply_event(Relay_log_info,apply_event_and_update_pos(Log_eve nt*,??,handle_slave_sql,pfs_spawn_thread,start_thread,clone
1 ??,??,handle_slave_io,pfs_spawn_thread,start_thread,clone
1 ??,??,??,??,handler::read_range_first(st_key_range,handler:: read_multi_range_first(st_key_multi_range**,QUICK_RANGE_SEL ECT::get_next(),??,mysql_update(THD*,mysql_execute_command( THD*),mysql_parse(THD*,Query_log_event::do_apply_event(Rela y_log_info,apply_event_and_update_pos(Log_event*,??,handle slave_sql,pfs_spawn_thread,start_thread,clone
1 ??,??,??,??,??,??,??,??,handler::read_range_first(st_key_ran ge,handler::read_multi_range_first(st_key_multi_range**,QUI CK_RANGE_SELECT::get_next(),??,mysql_update(THD*,mysql_exec ute_command(THD*),mysql_parse(THD*,Query_log_event::do_appl y_event(Relay_log_info,apply_event_and_update_pos(Log_event* ,??,handle_slave_sql,pfs_spawn_thread,start_thread,clone
1 get_table_share(THD*,open_table(THD*,open_tables(THD*,mys ql_update(THD*,mysql_execute_command(THD*),mysql_parse(THD* ,Query_log_event::do_apply_event(Relay_log_info,apply_event _and_update_pos(Log_event*,??,handle_slave_sql,pfs_spawn_th read,start_thread,clone

What is also interesting is that when we start MySQL replication on the percona5.5 slave the QPS is high but it slowly degrades overtime. [a lame workaround we’re using is to restart the sql thread every minute!]

Looking at the pmp output the Percona5.5 rhel6 box is spending lots of its time within cleanup_items(Item*),

So what I think is happening is that there is a session memory issue or some such and given the SQL thread uses that single ‘connection’, we’re having a performance regression.

I have graphs of bufferpool and queries though they really only reflect a slowly degrading server over time.

Have you guys come across this? Any suggestions would be appreciated!

Kind regards,

Trent Hornibrook
@mysqldbahelp

3

Trent,

Sorry for the slow reply. PMP output is useful here but could be misleading. I would suggest that since blocking doesn’t appear to be the problem, but rather actual consumption of CPU, that you look at oprofile instead. Let’s see what that reveals.