Checking Permissions thread state

[marcel]

Since upgrading from mysql 5.0.41 to Percona 5.1.57-rel12.8-log we are experiencing queries which are stuck in thread state “Checking Permissions”.

the issue is most obvious when running stored procedures and is not constant. After a mysql restart the issue will disappear, and will return after a few days.

Have not found any good hints on the internet on how to debug this.

any hints?

thanks

marcel

[sterin]

Did you run the mysql_upgrade command properly so that the privilege tables was updated?

[xaprb]

It is also possible that there is a bug in the version of MySQL you’re running. (Unlikely that it’s a bug in Percona’s modifications; we don’t change anything to do with privileges, although it’s possible that the bug is elsewhere and just manifests here.)

Next time it hangs, get stack traces with poormansprofiler.org and paste them here. Also, it depends on whether it’s idle when hung, or burning CPU time. If it’s burning CPU (not really hung, but just doing a lot of useless work), then run oprofile for 30 seconds and paste the opreport.

[marcel]

mysql_upgrade was not relevant, as we upgraded using an imported dump, so not direct binary data.

Will try to run poormansprofiler.org next time

thanks

marcel

[marcel]

We caught the problem red handed today, here the poormansprofiler output

hope it helps. mysql_upgrade didn’t give any relieve. reloading myql, adding more memory/moving tmp to ramdisk did not help.

Marcel

root@mysql1:~# ./poormansprofile.sh
108
49
pthread_cond_wait@@GLIBC_2.3.2 ,cache_thread,optimized,handle_one_connection,start_thread,c lone,??
36
lll_lock_wait,L_lock_1172,pthread_mutex_lock,fill_schema user_privileges,get_schema_tables_result,JOIN::exec,subselec t_single_select_engine::exec,Item_subselect::exec,Item_in_su bselect::val_bool,Item_in_optimizer::val_int,Item::val_bool, Item_func_not::val_int,Item::val_bool,Item_cond_and::val_int ,evaluate_join_record,sub_select,do_select,JOIN::exec,subsel ect_single_select_engine::exec,Item_subselect::exec,Item_in subselect::val_bool,Item_in_optimizer::val_int,Item::val_boo l,Item_cond_and::val_int,evaluate_join_record,sub_select,do select,JOIN::exec,mysql_select,handle_select,execute_sqlcom_ select,mysql_execute_command,mysql_open_cursor,sp_cursor::op en,sp_instr_copen::exec_core,sp_lex_keeper::reset_lex_and_ex ec_core,sp_instr_copen::execute,sp_head::execute,sp_head::ex ecute_procedure,mysql_execute_command,sp_instr_stmt::exec_co re,sp_lex_keeper::reset_lex_and_exec_core,sp_instr_stmt::exe cute,sp_head::execute,sp_head::execute_procedure,Event_job_d ata::execute,Event_worker_thread::run,event_worker_thread,st art_thread,clone,??
10
pthread_cond_wait@@GLIBC_2.3.2 ,os_event_wait_low,os_aio_simulated_handle,fil_aio_wait,io_h andler_thread,start_thread,clone,??
1 sigwait,signal_hand,start_thread,clone,??
1
pthread_cond_timedwait@@GLIBC_2.3.2,os_event_wait_time,srv_purge_thread,start_thread,clone,??
1
pthread_cond_timedwait@@GLIBC_2.3.2 ,os_event_wait_time,srv_monitor_thread,start_thread,clone,??
1
pthread_cond_timedwait@@GLIBC_2.3.2,os_event_wait_time,srv_master_thread,start_thread,clone,??
1
pthread_cond_timedwait@@GLIBC_2.3.2 ,os_event_wait_time,srv_LRU_dump_restore_thread,start_thread ,clone,??
1
pthread_cond_timedwait@@GLIBC_2.3.2 ,os_event_wait_time,srv_lock_timeout_thread,start_thread,clo ne,??
1
pthread_cond_timedwait@@GLIBC_2.3.2 ,os_event_wait_time,srv_error_monitor_thread,start_thread,cl one,??
1
pthread_cond_timedwait@@GLIBC_2.3.2 ,Event_queue::cond_wait,Event_queue::get_top_for_execution_i f_time,Event_scheduler::run,event_scheduler_thread,start_thr ead,clone,??
1 poll,handle_connections_sockets,main
1
memcpy,heap_scan,ha_heap::rnd_next,rr_sequential,sub_select, do_select,JOIN::exec,subselect_single_select_engine::exec,It em_subselect::exec,Item_in_subselect::val_bool,Item_in_optim izer::val_int,Item::val_bool,Item_func_not::val_int,Item::va l_bool,Item_cond_and::val_int,evaluate_join_record,sub_selec t,do_select,JOIN::exec,subselect_single_select_engine::exec, Item_subselect::exec,Item_in_subselect::val_bool,Item_in_opt imizer::val_int,Item::val_bool,Item_cond_and::val_int,evalua te_join_record,sub_select,do_select,JOIN::exec,mysql_select, handle_select,execute_sqlcom_select,mysql_execute_command,my sql_open_cursor,sp_cursor::open,sp_instr_copen::exec_core,sp lex_keeper::reset_lex_and_exec_core,sp_instr_copen::execute ,sp_head::execute,sp_head::execute_procedure,mysql_execute_c ommand,sp_instr_stmt::exec_core,sp_lex_keeper::reset_lex_and exec_core,sp_instr_stmt::execute,sp_head::execute,sp_head:: execute_procedure,Event_job_data::execute,Event_worker_threa d::run,event_worker_thread,start_thread,clone,??
1
block=0x7f046bbf3a58,block=0x7f046bbf3a58,block=0x7f046bbf 3a58,btr_search_guess_on_hash,btr_cur_search_to_nth_level,b tr_pcur_open_with_no_init_func,optimized,optimized,ha_innoba se::general_fetch,join_read_next_same,sub_select,evaluate_jo in_record,sub_select,evaluate_join_record,sub_select,do_sele ct,JOIN::exec,mysql_select,handle_select,execute_sqlcom_sele ct,mysql_execute_command,mysql_parse,dispatch_command,do_com mand,handle_one_connection,start_thread,clone,??
1
at,Item_in_optimizer::val_int,Item::val_bool,Item_func_not:: val_int,Item::val_bool,Item_cond_and::val_int,evaluate_join record,sub_select,do_select,JOIN::exec,subselect_single_sele ct_engine::exec,Item_subselect::exec,Item_in_subselect::val bool,Item_in_optimizer::val_int,Item::val_bool,Item_cond_and ::val_int,evaluate_join_record,sub_select,do_select,JOIN::ex ec,mysql_select,handle_select,execute_sqlcom_select,mysql_ex ecute_command,mysql_open_cursor,sp_cursor::open,sp_instr_cop en::exec_core,sp_lex_keeper::reset_lex_and_exec_core,sp_inst r_copen::execute,sp_head::execute,sp_head::execute_procedure ,mysql_execute_command,sp_instr_stmt::exec_core,sp_lex_keepe r::reset_lex_and_exec_core,sp_instr_stmt::execute,sp_head::e xecute,sp_head::execute_procedure,Event_job_data::execute,Ev ent_worker_thread::run,event_worker_thread,start_thread,clon e,??