On 3/18/2023 1:28 PM, mariadb@biblestuph.com wrote:
On 3/6/2023 3:58 AM, Sergei Golubchik wrote:
Hi, Dan,
On Mar 03, mariadb@Biblestuph.com wrote:
With this table:
CREATE TABLE t1 ( label varchar(100) NOT NULL, dt datetime NOT NULL, success tinyint(1) NOT NULL, PRIMARY KEY (label,dt), KEY dt (dt), KEY success (success,dt) ) ENGINE=InnoDB DEFAULT CHARSET=latin1 ROW_FORMAT=DYNAMIC
I have a DELETE query that has been stuck in Statistics for nearly an hour now:
DELETE MyDB.t1 FROM MyDB.t1 WHERE dt <= '2023-02-21 08:06:46' AND dt >= '2023-02-21 08:03:48'
This statement runs several times per hour to trim the table (and has for years). It has run fine against my 10.6.12 DB (this is a downstream replica DB) for a couple weeks now(when I upgraded the replica); but suddenly today produced the hang. Any ideas why? The table has nearly 15 million rows; but the rows are more or less evenly spaced across datetimes.
Is there any chance you could run https://poormansprofiler.org/ (or one of the alternatives) when this happens again?
Thanks for your reply. Later that same day I ended up having to force the server to die (kill -9); the thread never did let go and never left statistics; and since it was a replica thread it was preventing the replica from getting updated. I know that the server was getting some CPU while the thread was hung, but that may have only been the slave IO thread (which AFAICT was still running fine). And the server itself was responsive, so I was able to FLUSH all the tables (at least all but the one that it was working on) before I pulled the plug.
After I killed the server I restarted with skip-slave and immediately ANALYZEd the table in question, as well as all the other tables, before starting the slave again. I've not seen the issue since (and honestly hope I don't) but if so I will attempt to use the profiling technique you mentioned and report back here.
It just happened again today. A different replica this time, but the exact same statement. Here's the "Poor Man's Profile." Hope it is helpful: 26 pthread_cond_timedwait@@GLIBC_2.3.2,Thread_cache::park(),do_handle_one_connection(CONNECT*,,handle_one_connection,pfs_spawn_thread,start_thread,clone 2 pthread_cond_timedwait@@GLIBC_2.3.2,MYSQL_BIN_LOG::wait_for_update_binlog_end_pos(THD*,,mysql_binlog_send(THD*,,dispatch_command(enum_server_command,,do_command(THD*,,do_handle_one_connection(CONNECT*,,handle_one_connection,pfs_spawn_thread,start_thread,clone 1 syscall,tpool::aio_linux::getevent_thread_routine(tpool::aio_linux*),??,start_thread,clone 1 syscall,ssux_lock_impl<true>::wr_wait(unsigned,buf_page_get_low(page_id_t,,buf_page_get_gen(page_id_t,,btr_block_get(dict_index_t,btr_can_merge_with_page(btr_cur_t*,,btr_compress(btr_cur_t*,,btr_cur_compress_if_useful(btr_cur_t*,,btr_cur_pessimistic_delete(dberr_t*,,btr_cur_node_ptr_delete(btr_cur_t*,,btr_compress(btr_cur_t*,,btr_cur_compress_if_useful(btr_cur_t*,,btr_cur_pessimistic_delete(dberr_t*,,row_purge_remove_sec_if_poss_tree(purge_node_t*,,row_purge_record_func(purge_node_t*,,row_purge_step(que_thr_t*),que_run_threads(que_thr_t*),trx_purge(unsigned,purge_coordinator_callback(void*),tpool::task_group::execute(tpool::task*),tpool::thread_pool_generic::worker_main(tpool::worker_data*),??,start_thread,clone 1 syscall,srw_mutex_impl<true>::wait_and_lock(),buf_page_get_low(page_id_t,,buf_page_get_gen(page_id_t,,btr_block_get(dict_index_t,btr_estimate_n_rows_in_range(dict_index_t*,,ha_innobase::records_in_range(unsigned,handler::multi_range_read_info_const(unsigned,DsMrr_impl::dsmrr_info_const(unsigned,check_quick_select(PARAM*,,SQL_SELECT::test_quick_select(THD*,,JOIN::optimize_inner(),JOIN::optimize(),mysql_select(THD*,,mysql_execute_command(THD*,,mysql_parse(THD*,,Query_log_event::do_apply_event(rpl_group_info*,,apply_event_and_update_pos_apply(Log_event*,,rpt_handle_event(rpl_parallel_thread::queued_event*,,handle_rpl_parallel_thread,pfs_spawn_thread,start_thread,clone 1 sigwaitinfo,signal_hand,pfs_spawn_thread,start_thread,clone 1 pthread_cond_wait@@GLIBC_2.3.2,rpl_parallel_entry::choose_thread(rpl_group_info*,,rpl_parallel::do_event(rpl_group_info*,,handle_slave_sql,pfs_spawn_thread,start_thread,clone 1 pthread_cond_wait@@GLIBC_2.3.2,MYSQL_BIN_LOG::queue_for_group_commit(MYSQL_BIN_LOG::group_commit_entry*),MYSQL_BIN_LOG::write_transaction_to_binlog_events(MYSQL_BIN_LOG::group_commit_entry*),MYSQL_BIN_LOG::write_transaction_to_binlog(THD*,,binlog_flush_cache(THD*,,MYSQL_BIN_LOG::log_and_order(THD*,,ha_commit_trans(THD*,,trans_commit(THD*),Xid_log_event::do_commit(),Xid_apply_log_event::do_apply_event(rpl_group_info*),apply_event_and_update_pos_apply(Log_event*,,rpt_handle_event(rpl_parallel_thread::queued_event*,,handle_rpl_parallel_thread,pfs_spawn_thread,start_thread,clone 1 pthread_cond_wait@@GLIBC_2.3.2,handle_manager,pfs_spawn_thread,start_thread,clone 1 pthread_cond_wait@@GLIBC_2.3.2,buf_flush_page_cleaner(),??,start_thread,clone 1 pthread_cond_wait@@GLIBC_2.3.2,binlog_background_thread,pfs_spawn_thread,start_thread,clone 1 pthread_cond_timedwait@@GLIBC_2.3.2,tpool::thread_pool_generic::wait_for_tasks(std::unique_lock<std::mutex>&,,tpool::thread_pool_generic::get_task(tpool::worker_data*,,tpool::thread_pool_generic::worker_main(tpool::worker_data*),??,start_thread,clone 1 pthread_cond_timedwait@@GLIBC_2.3.2,timer_handler,start_thread,clone 1 pthread_cond_timedwait@@GLIBC_2.3.2,my_service_thread_sleep,ma_checkpoint_background,start_thread,clone 1 poll,vio_io_wait,vio_socket_io_wait,vio_ssl_read,my_real_read(st_net*,,my_net_read_packet_reallen,cli_safe_read_reallen,handle_slave_io,pfs_spawn_thread,start_thread,clone 1 poll,vio_io_wait,vio_socket_io_wait,vio_read,my_real_read(st_net*,,my_net_read_packet_reallen,my_net_read_packet,do_command(THD*,,do_handle_one_connection(CONNECT*,,handle_one_connection,pfs_spawn_thread,start_thread,clone 1 poll,handle_connections_sockets(),mysqld_main(int,,__libc_start_main,_start 1
Also I find that I cannot kill the query using KILL 12345; the KILL statement just comes back immediately without reporting an error and the statement continues. Is there no way to kill this statement without crashing the DB? Again, this is a replica statement that is executing. I had planned to stop the query, execute an ANALYZE TABLE t1 and then try it again, but I don't seem to be able to kill the query.
KILL always returns immediately. Killing in MariaDB is cooperative, it simply tells the thread "abort execution at your earliest convenience" and it's up to the executing thread to decide when to abort. KILL doesn't wait for it.
Yah, that's kind of what I figured. Is there a recommended (better) course of action other than kill -9 if this happens again?
Regards, Sergei VP of MariaDB Server Engineering and security@mariadb.org
_______________________________________________ Mailing list: https://launchpad.net/~maria-discuss Post to : maria-discuss@lists.launchpad.net Unsubscribe : https://launchpad.net/~maria-discuss More help : https://help.launchpad.net/ListHelp