On 3/18/2023 1:28 PM, mari...@biblestuph.com wrote:
On 3/6/2023 3:58 AM, Sergei Golubchik wrote:
Hi, Dan,
On Mar 03, mari...@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 secur...@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
_______________________________________________
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
