From 3aa83f709f44616a88fe069a52486913b534e551 Mon Sep 17 00:00:00 2001 From: Pekka Lampio Date: Mon, 6 May 2024 17:28:28 +0300 Subject: [PATCH 1/6] MDEV-28452 wsrep_ready: OFF after MDL BF-BF conflict. Galera Cluster failed when two transactions that were executed serially on a master node were incorrectly executed in parallel on a slave node. The slave node detected MDL BF-BF conflict and quit the cluster. The problem was caused by OPTIMIZE TABLE on a table that is the child table of a foreign key constraint. If UPDATE was performed on the parent table of the foreign key constraint while OPTIMIZE TABLE was running on the child table, the master node would run the transactions serially, but a slave node might run them in parallel resulting in MDL BF-BF conflict. The problem is fixed by adding foreign key constraint to the replicated write set preventing parallel apply of the transactions on the slave node. --- mysql-test/suite/galera/r/MDEV-28452.result | 70 +++++++++++++++ mysql-test/suite/galera/t/MDEV-28452.test | 98 +++++++++++++++++++++ sql/mdl.cc | 64 +++++++++++++- sql/sql_admin.cc | 45 +++++++++- sql/sql_base.cc | 19 ++++ sql/sql_show.cc | 3 + sql/wsrep_applier.cc | 3 + sql/wsrep_high_priority_service.cc | 9 ++ sql/wsrep_mysqld.cc | 13 ++- 9 files changed, 318 insertions(+), 6 deletions(-) create mode 100644 mysql-test/suite/galera/r/MDEV-28452.result create mode 100644 mysql-test/suite/galera/t/MDEV-28452.test diff --git a/mysql-test/suite/galera/r/MDEV-28452.result b/mysql-test/suite/galera/r/MDEV-28452.result new file mode 100644 index 0000000000000..c55adc58f7671 --- /dev/null +++ b/mysql-test/suite/galera/r/MDEV-28452.result @@ -0,0 +1,70 @@ +connection node_2; +connection node_1; +connect node_2a, 127.0.0.1, root, , test, $NODE_MYPORT_2; +connection node_1; +CREATE TABLE `user` ( +`id` char(36) COLLATE utf8mb4_unicode_ci NOT NULL, +`environment_id` char(36) COLLATE utf8mb4_unicode_ci NOT NULL, +`username` varchar(64) CHARACTER SET utf8mb4 COLLATE utf8mb4_bin NOT NULL, +`password` char(60) COLLATE utf8mb4_unicode_ci NOT NULL, +`status` enum('sign_up','invited','active','archived') +COLLATE utf8mb4_unicode_ci NOT NULL DEFAULT 'invited', +`token` char(64) COLLATE utf8mb4_unicode_ci DEFAULT NULL, +`token_valid_till` datetime DEFAULT NULL, +`last_login` datetime DEFAULT NULL, +`password_updated_at` datetime DEFAULT NULL, +`created_at` timestamp NULL DEFAULT NULL, +`updated_at` timestamp NULL DEFAULT NULL, +PRIMARY KEY (`id`), +UNIQUE KEY `user_username_unique` (`username`), +KEY `user_environment_id_index` (`environment_id`) +) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci; +CREATE TABLE `log_history_daily` ( +`type` enum('unknown','user','developer','api_key','api_env', +'mail_token','device') COLLATE utf8mb4_unicode_ci NOT NULL, +`status` enum('valid','invalid') COLLATE utf8mb4_unicode_ci NOT NULL, +`origin` enum('unknown','browser','go','android','ios','third_party') +COLLATE utf8mb4_unicode_ci NOT NULL DEFAULT 'unknown', +`ip` varchar(45) COLLATE utf8mb4_unicode_ci NOT NULL, +`value` varchar(255) CHARACTER SET utf8mb4 COLLATE utf8mb4_bin NOT NULL, +`user_id` char(36) COLLATE utf8mb4_unicode_ci DEFAULT NULL, +`date` date NOT NULL, +`count` int(10) unsigned NOT NULL, +`created_at` timestamp NULL DEFAULT NULL, +`updated_at` timestamp NULL DEFAULT NULL, +PRIMARY KEY (`type`,`status`,`origin`,`ip`,`value`,`date`), +KEY `log_history_daily_user_id_foreign` (`user_id`), +CONSTRAINT `log_history_daily_user_id_foreign` FOREIGN KEY (`user_id`) +REFERENCES `user` (`id`) ON DELETE SET NULL ON UPDATE CASCADE +) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci; +SET SESSION autocommit = 0; +INSERT INTO `user` VALUES ("id_1", "abc", "user 1", "secret", "active", +NULL, NULL, NULL, NULL, NULL, NULL); +INSERT INTO `log_history_daily` VALUES ("user", "valid", "unknown", +"192.168.0.1", "Sample", "id_1", "2024-04-22", 1, NULL, NULL); +COMMIT; +connection node_2; +SET GLOBAL wsrep_slave_threads = 2; +SELECT @@wsrep_slave_threads; +@@wsrep_slave_threads +2 +SET GLOBAL debug_dbug = "+d,sync.mdev_28452"; +connect node_1a, 127.0.0.1, root, , test, $NODE_MYPORT_1; +connection node_1a; +OPTIMIZE TABLE `log_history_daily`; +Table Op Msg_type Msg_text +test.log_history_daily optimize note Table does not support optimize, doing recreate + analyze instead +test.log_history_daily optimize status OK +COMMIT; +connection node_1; +UPDATE `user` SET `last_login` = '2024-04-23' WHERE `id`="id_1"; +COMMIT; +connection node_2a; +SET GLOBAL debug_dbug = 'RESET'; +SET DEBUG_SYNC = 'now SIGNAL signal.mdev_28452'; +SET DEBUG_SYNC = 'RESET'; +connection node_1; +DROP TABLE `log_history_daily`; +DROP TABLE `user`; +connection node_2; +SET GLOBAL wsrep_slave_threads = DEFAULT; diff --git a/mysql-test/suite/galera/t/MDEV-28452.test b/mysql-test/suite/galera/t/MDEV-28452.test new file mode 100644 index 0000000000000..b53624fed7a26 --- /dev/null +++ b/mysql-test/suite/galera/t/MDEV-28452.test @@ -0,0 +1,98 @@ +# +# Test for MDEV-28452: wsrep_ready: OFF after MDL BF-BF conflict +# + +--source include/galera_cluster.inc +--source include/have_debug.inc +--source include/have_debug_sync.inc + +--connect node_2a, 127.0.0.1, root, , test, $NODE_MYPORT_2 + +--connection node_1 + +# create two tables +CREATE TABLE `user` ( + `id` char(36) COLLATE utf8mb4_unicode_ci NOT NULL, + `environment_id` char(36) COLLATE utf8mb4_unicode_ci NOT NULL, + `username` varchar(64) CHARACTER SET utf8mb4 COLLATE utf8mb4_bin NOT NULL, + `password` char(60) COLLATE utf8mb4_unicode_ci NOT NULL, + `status` enum('sign_up','invited','active','archived') + COLLATE utf8mb4_unicode_ci NOT NULL DEFAULT 'invited', + `token` char(64) COLLATE utf8mb4_unicode_ci DEFAULT NULL, + `token_valid_till` datetime DEFAULT NULL, + `last_login` datetime DEFAULT NULL, + `password_updated_at` datetime DEFAULT NULL, + `created_at` timestamp NULL DEFAULT NULL, + `updated_at` timestamp NULL DEFAULT NULL, + PRIMARY KEY (`id`), + UNIQUE KEY `user_username_unique` (`username`), + KEY `user_environment_id_index` (`environment_id`) +) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci; + + +CREATE TABLE `log_history_daily` ( + `type` enum('unknown','user','developer','api_key','api_env', + 'mail_token','device') COLLATE utf8mb4_unicode_ci NOT NULL, + `status` enum('valid','invalid') COLLATE utf8mb4_unicode_ci NOT NULL, + `origin` enum('unknown','browser','go','android','ios','third_party') + COLLATE utf8mb4_unicode_ci NOT NULL DEFAULT 'unknown', + `ip` varchar(45) COLLATE utf8mb4_unicode_ci NOT NULL, + `value` varchar(255) CHARACTER SET utf8mb4 COLLATE utf8mb4_bin NOT NULL, + `user_id` char(36) COLLATE utf8mb4_unicode_ci DEFAULT NULL, + `date` date NOT NULL, + `count` int(10) unsigned NOT NULL, + `created_at` timestamp NULL DEFAULT NULL, + `updated_at` timestamp NULL DEFAULT NULL, + PRIMARY KEY (`type`,`status`,`origin`,`ip`,`value`,`date`), + KEY `log_history_daily_user_id_foreign` (`user_id`), + CONSTRAINT `log_history_daily_user_id_foreign` FOREIGN KEY (`user_id`) + REFERENCES `user` (`id`) ON DELETE SET NULL ON UPDATE CASCADE +) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci; + +SET SESSION autocommit = 0; + +# insert one row in each table +INSERT INTO `user` VALUES ("id_1", "abc", "user 1", "secret", "active", + NULL, NULL, NULL, NULL, NULL, NULL); +INSERT INTO `log_history_daily` VALUES ("user", "valid", "unknown", + "192.168.0.1", "Sample", "id_1", "2024-04-22", 1, NULL, NULL); +COMMIT; + +# Start two slave threads in node 2. +# Set up a synchronizaton point (sync.mdev_28452) for slave thread 1 +# where the thread stops when it holds an exclusive metadata lock +# (MDL_EXCLUSIVE) for the OPTIMIZE TABLE statement (see below). +--connection node_2 +SET GLOBAL wsrep_slave_threads = 2; +SELECT @@wsrep_slave_threads; +SET GLOBAL debug_dbug = "+d,sync.mdev_28452"; + +# Run two transactions in parallel in node 1: +# 1) OPTIMIZE TABLE on the child table of the foreign key constraint, +--connect node_1a, 127.0.0.1, root, , test, $NODE_MYPORT_1 +--connection node_1a +--sleep 5 +OPTIMIZE TABLE `log_history_daily`; +COMMIT; + +# 2) and UPDATE on the parent table of the foreign key constraint. +--connection node_1 +# update the row in "user" so that it affects the foreign key in +# "log_history_daily" +UPDATE `user` SET `last_login` = '2024-04-23' WHERE `id`="id_1"; +COMMIT; + +# allow the stopped OPTIMIZE TABLE transaction to proceed +--connection node_2a +--sleep 5 +SET GLOBAL debug_dbug = 'RESET'; +SET DEBUG_SYNC = 'now SIGNAL signal.mdev_28452'; +SET DEBUG_SYNC = 'RESET'; + +# cleanup +--connection node_1 +--sleep 5 +DROP TABLE `log_history_daily`; +DROP TABLE `user`; +--connection node_2 +SET GLOBAL wsrep_slave_threads = DEFAULT; diff --git a/sql/mdl.cc b/sql/mdl.cc index 30aaf8311c512..b7993964e885c 100644 --- a/sql/mdl.cc +++ b/sql/mdl.cc @@ -1752,6 +1752,9 @@ MDL_lock::can_grant_lock(enum_mdl_type type_arg, bitmap_t granted_incompat_map= incompatible_granted_types_bitmap()[type_arg]; #ifdef WITH_WSREP + WSREP_INFO("DEBUG: %s: thd=%lu, %s", __FUNCTION__, + thd_get_thread_id(requestor_ctx->get_thd()), + wsrep_thd_query(requestor_ctx->get_thd())); /* Approve lock request in BACKUP namespace for BF threads. */ @@ -2132,6 +2135,9 @@ MDL_context::try_acquire_lock_impl(MDL_request *mdl_request, ticket->m_lock= lock; +#ifdef WITH_WSREP + WSREP_INFO("DEBUG: %s", __FUNCTION__); +#endif if (lock->can_grant_lock(mdl_request->type, this, false)) { lock->m_granted.add_ticket(ticket); @@ -2143,6 +2149,10 @@ MDL_context::try_acquire_lock_impl(MDL_request *mdl_request, mdl_request->ticket= ticket; mysql_mdl_set_status(ticket->m_psi, MDL_ticket::GRANTED); +#ifdef WITH_WSREP + WSREP_INFO("DEBUG: %s: mdl request %p, ticket %p granted", + __FUNCTION__, mdl_request, ticket); +#endif } else *out_ticket= ticket; @@ -2189,9 +2199,13 @@ MDL_context::clone_ticket(MDL_request *mdl_request) #ifndef DBUG_OFF , mdl_request->duration #endif - ))) + ))) { +#ifdef WITH_WSREP + WSREP_INFO("calling MDL_ticket::create()"); +#endif return TRUE; - + } + DBUG_ASSERT(ticket->m_psi == NULL); ticket->m_psi= mysql_mdl_create(ticket, &mdl_request->key, @@ -2296,6 +2310,10 @@ MDL_context::acquire_lock(MDL_request *mdl_request, double lock_wait_timeout) if (try_acquire_lock_impl(mdl_request, &ticket)) { DBUG_PRINT("mdl", ("OOM: %s", mdl_lock_name)); +#ifdef WITH_WSREP + WSREP_INFO("DEBUG: %s(%u): MDL request %p --> FALSE", __FUNCTION__, + __LINE__, mdl_request); +#endif DBUG_RETURN(TRUE); } @@ -2308,6 +2326,29 @@ MDL_context::acquire_lock(MDL_request *mdl_request, double lock_wait_timeout) */ DBUG_PRINT("info", ("Got lock without waiting")); DBUG_PRINT("mdl", ("Seized: %s", dbug_print_mdl(mdl_request->ticket))); +#ifdef WITH_WSREP + WSREP_INFO("DEBUG: %s(%u): Seized %s : MDL request %p --> FALSE", __FUNCTION__, + __LINE__, dbug_print_mdl(mdl_request->ticket), mdl_request); +#ifdef ENABLED_DEBUG_SYNC + if (0 == strcmp(dbug_print_mdl(mdl_request->ticket), + "test/log_history_daily (MDL_EXCLUSIVE)")) { +#ifdef WITH_WSREP + WSREP_INFO("DEBUG: DBUG_EXECUTE_IF: %s(%u)", __FUNCTION__, __LINE__); +#endif + DBUG_EXECUTE_IF("sync.mdev_28452", + { + const char act[]= + "now " + "wait_for signal.mdev_28452"; + DBUG_ASSERT(!debug_sync_set_action(get_thd(), + STRING_WITH_LEN(act))); + };); +#ifdef WITH_WSREP + WSREP_INFO("DEBUG: DBUG_EXECUTE_IF: %s(%u)", __FUNCTION__, __LINE__); +#endif + } +#endif /* ENABLED_DEBUG_SYNC */ +#endif DBUG_RETURN(FALSE); } @@ -2329,6 +2370,10 @@ MDL_context::acquire_lock(MDL_request *mdl_request, double lock_wait_timeout) mysql_prlock_unlock(&lock->m_rwlock); MDL_ticket::destroy(ticket); my_error(ER_LOCK_WAIT_TIMEOUT, MYF(0)); +#ifdef WITH_WSREP + WSREP_INFO("DEBUG: %s(%u): MDL request %p --> TRUE", __FUNCTION__, + __LINE__, mdl_request); +#endif DBUG_RETURN(TRUE); } @@ -2446,6 +2491,10 @@ MDL_context::acquire_lock(MDL_request *mdl_request, double lock_wait_timeout) DBUG_ASSERT(0); break; } +#ifdef WITH_WSREP + WSREP_INFO("DEBUG: %s(%u): MDL request %p --> TRUE", __FUNCTION__, + __LINE__, mdl_request); +#endif DBUG_RETURN(TRUE); } @@ -2464,6 +2513,13 @@ MDL_context::acquire_lock(MDL_request *mdl_request, double lock_wait_timeout) mysql_mdl_set_status(ticket->m_psi, MDL_ticket::GRANTED); DBUG_PRINT("mdl", ("Acquired: %s", ticket_msg)); +#ifdef WITH_WSREP + WSREP_INFO("DEBUG: Acquired: %s", ticket_msg); +#endif +#ifdef WITH_WSREP + WSREP_INFO("DEBUG: %s(%u): MDL request %p --> FALSE", __FUNCTION__, + __LINE__, mdl_request); +#endif DBUG_RETURN(FALSE); } @@ -2886,7 +2942,9 @@ void MDL_context::release_lock(enum_mdl_duration duration, MDL_ticket *ticket) DBUG_ASSERT(this == ticket->get_ctx()); DBUG_PRINT("mdl", ("Released: %s", dbug_print_mdl(ticket))); - +#ifdef WITH_WSREP + WSREP_INFO("DEBUG: %s: Released: %s", __FUNCTION__, dbug_print_mdl(ticket)); +#endif lock->remove_ticket(m_pins, &MDL_lock::m_granted, ticket); m_tickets[duration].remove(ticket); diff --git a/sql/sql_admin.cc b/sql/sql_admin.cc index 2b4c99ebc9de6..b78fa4f72dc12 100644 --- a/sql/sql_admin.cc +++ b/sql/sql_admin.cc @@ -1603,12 +1603,52 @@ bool Sql_cmd_optimize_table::execute(THD *thd) bool res= TRUE; Recreate_info recreate_info; DBUG_ENTER("Sql_cmd_optimize_table::execute"); - +#ifdef WITH_WSREP + WSREP_INFO("DEBUG: Sql_cmd_optimize_table::execute: enter"); + for (TABLE_LIST *table= first_table; table; table= table->next_local) { + WSREP_INFO("DEBUG: Sql_cmd_optimize_table::execute: table = %s", + table->table_name.str); + } + +#endif if (check_table_access(thd, SELECT_ACL | INSERT_ACL, first_table, FALSE, UINT_MAX, FALSE)) goto error; /* purecov: inspected */ +#if defined(WITH_WSREP) && !defined(REMOVED) + if (WSREP(thd) && + (!thd->is_current_stmt_binlog_format_row() || + !thd->find_temporary_table(first_table))) + { + /* + It makes sense to set auto_increment_* to defaults in TOI operations. + Must be done before wsrep_TOI_begin() since Query_log_event encapsulating + TOI statement and auto inc variables for wsrep replication is constructed + there. Variables are reset back in THD::reset_for_next_command() before + processing of next command. + */ + if (wsrep_auto_increment_control) + { + thd->variables.auto_increment_offset = 1; + thd->variables.auto_increment_increment = 1; + } + + wsrep::key_array keys; + if (!wsrep_append_fk_parent_table(thd, first_table, &keys)) + { + WSREP_INFO("DEBUG: %s(%u): #keys = %u", __FUNCTION__, __LINE__, keys.size()); + WSREP_TO_ISOLATION_BEGIN_ALTER(first_table->db.str, + first_table->table_name.str, + first_table, NULL, &keys, NULL) + { + WSREP_WARN("OPTIMIZE TABLE isolation failure"); + DBUG_RETURN(TRUE); + } + } + } +#else WSREP_TO_ISOLATION_BEGIN_WRTCHK(NULL, NULL, first_table); +#endif /* WITH_WSREP */ res= (specialflag & SPECIAL_NO_NEW_FUNC) ? mysql_recreate_table(thd, first_table, &recreate_info, true) : mysql_admin_table(thd, first_table, &m_lex->check_opt, @@ -1618,7 +1658,10 @@ bool Sql_cmd_optimize_table::execute(THD *thd) m_lex->query_tables= first_table; #ifdef WITH_WSREP + WSREP_INFO("DEBUG: Sql_cmd_optimize_table::execute: leave"); +#if 0 wsrep_error_label: +#endif #endif /* WITH_WSREP */ error: DBUG_RETURN(res); diff --git a/sql/sql_base.cc b/sql/sql_base.cc index 47006978709de..b86d695ac802b 100644 --- a/sql/sql_base.cc +++ b/sql/sql_base.cc @@ -1556,6 +1556,9 @@ open_table_get_mdl_lock(THD *thd, Open_table_context *ot_ctx, To avoid such situation we skip the trouble-making table if there is a conflicting lock. */ +#ifdef WITH_WSREP + WSREP_INFO("DEBUG: %s(%u)", __FUNCTION__, __LINE__); +#endif if (thd->mdl_context.try_acquire_lock(mdl_request)) return TRUE; if (mdl_request->ticket == NULL) @@ -3663,6 +3666,13 @@ open_and_process_table(THD *thd, TABLE_LIST *tables, uint *counter, uint flags, DBUG_ENTER("open_and_process_table"); DEBUG_SYNC(thd, "open_and_process_table"); +#ifdef WITH_WSREP + WSREP_INFO("DEBUG: %s: table: %p name: %s db: %s flags: %u", __FUNCTION__, + tables, tables->table_name.str, + tables->db.str, tables->for_insert_data); + +#endif + /* Ignore placeholders for derived tables. After derived tables processing, link to created temporary table will be put here. @@ -4103,6 +4113,9 @@ lock_table_names(THD *thd, const DDL_options_st &options, MDL_STATEMENT); mdl_savepoint= thd->mdl_context.mdl_savepoint(); +#ifdef WITH_WSREP + WSREP_INFO("DEBUG: %s(%u)", __FUNCTION__, __LINE__); +#endif while (!thd->mdl_context.acquire_locks(&mdl_requests, lock_wait_timeout) && !upgrade_lock_if_not_exists(thd, options, tables_start, lock_wait_timeout) && @@ -4802,6 +4815,12 @@ bool DML_prelocking_strategy::handle_table(THD *thd, /* We rely on a caller to check that table is going to be changed. */ DBUG_ASSERT(table_list->lock_type >= TL_FIRST_WRITE || thd->lex->default_used); +#ifdef WITH_WSREP + WSREP_INFO("DEBUG: handle_table: table: %p name: %s db: %s flags: %u", + table_list, table_list->table_name.str, + table_list->db.str, table_list->for_insert_data); + +#endif if (table_list->trg_event_map) { diff --git a/sql/sql_show.cc b/sql/sql_show.cc index 40e8a800b2604..20caaac62efad 100644 --- a/sql/sql_show.cc +++ b/sql/sql_show.cc @@ -4899,6 +4899,9 @@ try_acquire_high_prio_shared_mdl_lock(THD *thd, TABLE_LIST *table, other locked tables, we prefer not to wait on a conflicting lock. */ +#ifdef WITH_WSREP + WSREP_INFO("DEBUG: %s(%u)", __FUNCTION__, __LINE__); +#endif error= thd->mdl_context.try_acquire_lock(&table->mdl_request); } else diff --git a/sql/wsrep_applier.cc b/sql/wsrep_applier.cc index 8767f698bf2e6..827e12eb8000d 100644 --- a/sql/wsrep_applier.cc +++ b/sql/wsrep_applier.cc @@ -213,6 +213,9 @@ int wsrep_apply_events(THD* thd, exec_res= ev->apply_event(thd->wsrep_rgi); DBUG_PRINT("info", ("exec_event result: %d", exec_res)); + WSREP_INFO("Event %d %s applied: rcode %d, seqno %lld", + event, ev->get_type_str(), exec_res, + (long long) wsrep_thd_trx_seqno(thd)); if (exec_res) { WSREP_WARN("Event %d %s apply failed: %d, seqno %lld", diff --git a/sql/wsrep_high_priority_service.cc b/sql/wsrep_high_priority_service.cc index ecb0e487f2b37..1be9912412f66 100644 --- a/sql/wsrep_high_priority_service.cc +++ b/sql/wsrep_high_priority_service.cc @@ -125,6 +125,7 @@ static int apply_events(THD* thd, const wsrep::const_buffer& data, wsrep::mutable_buffer& err) { + WSREP_INFO("DEBUG: %s: thd = %llu", __FUNCTION__, thd->thread_id); int const ret= wsrep_apply_events(thd, rli, data.data(), data.size()); if (ret || wsrep_thd_has_ignored_error(thd)) { @@ -425,6 +426,10 @@ int Wsrep_high_priority_service::apply_toi(const wsrep::ws_meta& ws_meta, };); #endif + WSREP_INFO("DEBUG: %s: thd = %llu, ws seqno = %llu, flags = %s, client = %llu", + __FUNCTION__, thd->thread_id, ws_meta.seqno(), + wsrep::flags_to_string(ws_meta.flags()).c_str(), + ws_meta.client_id()); int ret= apply_events(thd, m_rli, data, err); wsrep_thd_set_ignored_error(thd, false); trans_commit(thd); @@ -592,6 +597,10 @@ int Wsrep_applier_service::apply_write_set(const wsrep::ws_meta& ws_meta, };); #endif /* ENABLED_DEBUG_SYNC */ + WSREP_INFO("DEBUG: %s: thd = %llu, ws seqno = %llu, flags = %s, client = %llu", + __FUNCTION__, thd->thread_id, ws_meta.seqno(), + wsrep::flags_to_string(ws_meta.flags()).c_str(), + ws_meta.client_id()); wsrep_setup_uk_and_fk_checks(thd); int ret= apply_events(thd, m_rli, data, err); diff --git a/sql/wsrep_mysqld.cc b/sql/wsrep_mysqld.cc index d48ad74d6fedd..b7951fbfbede7 100644 --- a/sql/wsrep_mysqld.cc +++ b/sql/wsrep_mysqld.cc @@ -2693,7 +2693,7 @@ static int wsrep_TOI_begin(THD *thd, const char *db, const char *table, { DBUG_ASSERT(wsrep_OSU_method_get(thd) == WSREP_OSU_TOI); - WSREP_DEBUG("TOI Begin: %s", wsrep_thd_query(thd)); + WSREP_INFO("TOI Begin: %s, fk_tables = %p", wsrep_thd_query(thd), fk_tables); if (wsrep_can_run_in_toi(thd, db, table, table_list, create_info) == false) { @@ -2738,6 +2738,14 @@ static int wsrep_TOI_begin(THD *thd, const char *db, const char *table, int ret= cs.enter_toi_local(key_array, wsrep::const_buffer(buff.ptr, buff.len)); + WSREP_INFO("DEBUG: %s(%u): ret = %d, #key_array = %u", __FUNCTION__, __LINE__, ret, + key_array.size() + ); + std::ostringstream ostream; + for (uint i = 0; i < key_array.size(); i++) { + ostream << "Key " << i << ":" << key_array[i] << ". "; + } + WSREP_INFO("DEBUG: %s(%u): keys: %s", __FUNCTION__, __LINE__, ostream.str().c_str()); if (ret) { @@ -2819,6 +2827,7 @@ static int wsrep_TOI_begin(THD *thd, const char *db, const char *table, if (rc) wsrep_TOI_begin_failed(thd, NULL); + WSREP_INFO("DEBUG: %s(%u): rc = %d", __FUNCTION__, __LINE__, rc); return rc; } @@ -2826,7 +2835,7 @@ static void wsrep_TOI_end(THD *thd) { wsrep_to_isolation--; wsrep::client_state& client_state(thd->wsrep_cs()); DBUG_ASSERT(wsrep_thd_is_local_toi(thd)); - WSREP_DEBUG("TO END: %lld: %s", client_state.toi_meta().seqno().get(), + WSREP_INFO("TO END: %lld: %s", client_state.toi_meta().seqno().get(), wsrep_thd_query(thd)); wsrep_gtid_server.signal_waiters(thd->wsrep_current_gtid_seqno, false); From d456e1382d7b9305ec4f4c3cd298827bf15d3cae Mon Sep 17 00:00:00 2001 From: Pekka Lampio Date: Tue, 7 May 2024 15:36:28 +0300 Subject: [PATCH 2/6] Code cleanup. Removed debug messages. --- mysql-test/suite/galera/t/MDEV-28452.test | 8 ++-- sql/mdl.cc | 51 ++--------------------- sql/sql_admin.cc | 18 +------- sql/sql_base.cc | 19 --------- sql/sql_show.cc | 3 -- sql/wsrep_applier.cc | 3 -- sql/wsrep_high_priority_service.cc | 9 ---- sql/wsrep_mysqld.cc | 13 +----- 8 files changed, 12 insertions(+), 112 deletions(-) diff --git a/mysql-test/suite/galera/t/MDEV-28452.test b/mysql-test/suite/galera/t/MDEV-28452.test index b53624fed7a26..b53bf344e6553 100644 --- a/mysql-test/suite/galera/t/MDEV-28452.test +++ b/mysql-test/suite/galera/t/MDEV-28452.test @@ -17,7 +17,7 @@ CREATE TABLE `user` ( `username` varchar(64) CHARACTER SET utf8mb4 COLLATE utf8mb4_bin NOT NULL, `password` char(60) COLLATE utf8mb4_unicode_ci NOT NULL, `status` enum('sign_up','invited','active','archived') - COLLATE utf8mb4_unicode_ci NOT NULL DEFAULT 'invited', + COLLATE utf8mb4_unicode_ci NOT NULL DEFAULT 'invited', `token` char(64) COLLATE utf8mb4_unicode_ci DEFAULT NULL, `token_valid_till` datetime DEFAULT NULL, `last_login` datetime DEFAULT NULL, @@ -32,10 +32,10 @@ CREATE TABLE `user` ( CREATE TABLE `log_history_daily` ( `type` enum('unknown','user','developer','api_key','api_env', - 'mail_token','device') COLLATE utf8mb4_unicode_ci NOT NULL, + 'mail_token','device') COLLATE utf8mb4_unicode_ci NOT NULL, `status` enum('valid','invalid') COLLATE utf8mb4_unicode_ci NOT NULL, `origin` enum('unknown','browser','go','android','ios','third_party') - COLLATE utf8mb4_unicode_ci NOT NULL DEFAULT 'unknown', + COLLATE utf8mb4_unicode_ci NOT NULL DEFAULT 'unknown', `ip` varchar(45) COLLATE utf8mb4_unicode_ci NOT NULL, `value` varchar(255) CHARACTER SET utf8mb4 COLLATE utf8mb4_bin NOT NULL, `user_id` char(36) COLLATE utf8mb4_unicode_ci DEFAULT NULL, @@ -46,7 +46,7 @@ CREATE TABLE `log_history_daily` ( PRIMARY KEY (`type`,`status`,`origin`,`ip`,`value`,`date`), KEY `log_history_daily_user_id_foreign` (`user_id`), CONSTRAINT `log_history_daily_user_id_foreign` FOREIGN KEY (`user_id`) - REFERENCES `user` (`id`) ON DELETE SET NULL ON UPDATE CASCADE + REFERENCES `user` (`id`) ON DELETE SET NULL ON UPDATE CASCADE ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci; SET SESSION autocommit = 0; diff --git a/sql/mdl.cc b/sql/mdl.cc index b7993964e885c..fb6c5a592f271 100644 --- a/sql/mdl.cc +++ b/sql/mdl.cc @@ -1752,9 +1752,6 @@ MDL_lock::can_grant_lock(enum_mdl_type type_arg, bitmap_t granted_incompat_map= incompatible_granted_types_bitmap()[type_arg]; #ifdef WITH_WSREP - WSREP_INFO("DEBUG: %s: thd=%lu, %s", __FUNCTION__, - thd_get_thread_id(requestor_ctx->get_thd()), - wsrep_thd_query(requestor_ctx->get_thd())); /* Approve lock request in BACKUP namespace for BF threads. */ @@ -2135,9 +2132,6 @@ MDL_context::try_acquire_lock_impl(MDL_request *mdl_request, ticket->m_lock= lock; -#ifdef WITH_WSREP - WSREP_INFO("DEBUG: %s", __FUNCTION__); -#endif if (lock->can_grant_lock(mdl_request->type, this, false)) { lock->m_granted.add_ticket(ticket); @@ -2149,10 +2143,6 @@ MDL_context::try_acquire_lock_impl(MDL_request *mdl_request, mdl_request->ticket= ticket; mysql_mdl_set_status(ticket->m_psi, MDL_ticket::GRANTED); -#ifdef WITH_WSREP - WSREP_INFO("DEBUG: %s: mdl request %p, ticket %p granted", - __FUNCTION__, mdl_request, ticket); -#endif } else *out_ticket= ticket; @@ -2199,13 +2189,9 @@ MDL_context::clone_ticket(MDL_request *mdl_request) #ifndef DBUG_OFF , mdl_request->duration #endif - ))) { -#ifdef WITH_WSREP - WSREP_INFO("calling MDL_ticket::create()"); -#endif + ))) return TRUE; - } - + DBUG_ASSERT(ticket->m_psi == NULL); ticket->m_psi= mysql_mdl_create(ticket, &mdl_request->key, @@ -2310,10 +2296,6 @@ MDL_context::acquire_lock(MDL_request *mdl_request, double lock_wait_timeout) if (try_acquire_lock_impl(mdl_request, &ticket)) { DBUG_PRINT("mdl", ("OOM: %s", mdl_lock_name)); -#ifdef WITH_WSREP - WSREP_INFO("DEBUG: %s(%u): MDL request %p --> FALSE", __FUNCTION__, - __LINE__, mdl_request); -#endif DBUG_RETURN(TRUE); } @@ -2327,14 +2309,9 @@ MDL_context::acquire_lock(MDL_request *mdl_request, double lock_wait_timeout) DBUG_PRINT("info", ("Got lock without waiting")); DBUG_PRINT("mdl", ("Seized: %s", dbug_print_mdl(mdl_request->ticket))); #ifdef WITH_WSREP - WSREP_INFO("DEBUG: %s(%u): Seized %s : MDL request %p --> FALSE", __FUNCTION__, - __LINE__, dbug_print_mdl(mdl_request->ticket), mdl_request); #ifdef ENABLED_DEBUG_SYNC if (0 == strcmp(dbug_print_mdl(mdl_request->ticket), "test/log_history_daily (MDL_EXCLUSIVE)")) { -#ifdef WITH_WSREP - WSREP_INFO("DEBUG: DBUG_EXECUTE_IF: %s(%u)", __FUNCTION__, __LINE__); -#endif DBUG_EXECUTE_IF("sync.mdev_28452", { const char act[]= @@ -2343,12 +2320,9 @@ MDL_context::acquire_lock(MDL_request *mdl_request, double lock_wait_timeout) DBUG_ASSERT(!debug_sync_set_action(get_thd(), STRING_WITH_LEN(act))); };); -#ifdef WITH_WSREP - WSREP_INFO("DEBUG: DBUG_EXECUTE_IF: %s(%u)", __FUNCTION__, __LINE__); -#endif } #endif /* ENABLED_DEBUG_SYNC */ -#endif +#endif /* WITH_WSREP! */ DBUG_RETURN(FALSE); } @@ -2370,10 +2344,6 @@ MDL_context::acquire_lock(MDL_request *mdl_request, double lock_wait_timeout) mysql_prlock_unlock(&lock->m_rwlock); MDL_ticket::destroy(ticket); my_error(ER_LOCK_WAIT_TIMEOUT, MYF(0)); -#ifdef WITH_WSREP - WSREP_INFO("DEBUG: %s(%u): MDL request %p --> TRUE", __FUNCTION__, - __LINE__, mdl_request); -#endif DBUG_RETURN(TRUE); } @@ -2491,10 +2461,6 @@ MDL_context::acquire_lock(MDL_request *mdl_request, double lock_wait_timeout) DBUG_ASSERT(0); break; } -#ifdef WITH_WSREP - WSREP_INFO("DEBUG: %s(%u): MDL request %p --> TRUE", __FUNCTION__, - __LINE__, mdl_request); -#endif DBUG_RETURN(TRUE); } @@ -2513,13 +2479,6 @@ MDL_context::acquire_lock(MDL_request *mdl_request, double lock_wait_timeout) mysql_mdl_set_status(ticket->m_psi, MDL_ticket::GRANTED); DBUG_PRINT("mdl", ("Acquired: %s", ticket_msg)); -#ifdef WITH_WSREP - WSREP_INFO("DEBUG: Acquired: %s", ticket_msg); -#endif -#ifdef WITH_WSREP - WSREP_INFO("DEBUG: %s(%u): MDL request %p --> FALSE", __FUNCTION__, - __LINE__, mdl_request); -#endif DBUG_RETURN(FALSE); } @@ -2942,9 +2901,7 @@ void MDL_context::release_lock(enum_mdl_duration duration, MDL_ticket *ticket) DBUG_ASSERT(this == ticket->get_ctx()); DBUG_PRINT("mdl", ("Released: %s", dbug_print_mdl(ticket))); -#ifdef WITH_WSREP - WSREP_INFO("DEBUG: %s: Released: %s", __FUNCTION__, dbug_print_mdl(ticket)); -#endif + lock->remove_ticket(m_pins, &MDL_lock::m_granted, ticket); m_tickets[duration].remove(ticket); diff --git a/sql/sql_admin.cc b/sql/sql_admin.cc index b78fa4f72dc12..be6df8b72f3f4 100644 --- a/sql/sql_admin.cc +++ b/sql/sql_admin.cc @@ -1603,19 +1603,12 @@ bool Sql_cmd_optimize_table::execute(THD *thd) bool res= TRUE; Recreate_info recreate_info; DBUG_ENTER("Sql_cmd_optimize_table::execute"); -#ifdef WITH_WSREP - WSREP_INFO("DEBUG: Sql_cmd_optimize_table::execute: enter"); - for (TABLE_LIST *table= first_table; table; table= table->next_local) { - WSREP_INFO("DEBUG: Sql_cmd_optimize_table::execute: table = %s", - table->table_name.str); - } - -#endif + if (check_table_access(thd, SELECT_ACL | INSERT_ACL, first_table, FALSE, UINT_MAX, FALSE)) goto error; /* purecov: inspected */ -#if defined(WITH_WSREP) && !defined(REMOVED) +#ifdef WITH_WSREP if (WSREP(thd) && (!thd->is_current_stmt_binlog_format_row() || !thd->find_temporary_table(first_table))) @@ -1636,7 +1629,6 @@ bool Sql_cmd_optimize_table::execute(THD *thd) wsrep::key_array keys; if (!wsrep_append_fk_parent_table(thd, first_table, &keys)) { - WSREP_INFO("DEBUG: %s(%u): #keys = %u", __FUNCTION__, __LINE__, keys.size()); WSREP_TO_ISOLATION_BEGIN_ALTER(first_table->db.str, first_table->table_name.str, first_table, NULL, &keys, NULL) @@ -1657,12 +1649,6 @@ bool Sql_cmd_optimize_table::execute(THD *thd) m_lex->first_select_lex()->table_list.first= first_table; m_lex->query_tables= first_table; -#ifdef WITH_WSREP - WSREP_INFO("DEBUG: Sql_cmd_optimize_table::execute: leave"); -#if 0 -wsrep_error_label: -#endif -#endif /* WITH_WSREP */ error: DBUG_RETURN(res); } diff --git a/sql/sql_base.cc b/sql/sql_base.cc index b86d695ac802b..47006978709de 100644 --- a/sql/sql_base.cc +++ b/sql/sql_base.cc @@ -1556,9 +1556,6 @@ open_table_get_mdl_lock(THD *thd, Open_table_context *ot_ctx, To avoid such situation we skip the trouble-making table if there is a conflicting lock. */ -#ifdef WITH_WSREP - WSREP_INFO("DEBUG: %s(%u)", __FUNCTION__, __LINE__); -#endif if (thd->mdl_context.try_acquire_lock(mdl_request)) return TRUE; if (mdl_request->ticket == NULL) @@ -3666,13 +3663,6 @@ open_and_process_table(THD *thd, TABLE_LIST *tables, uint *counter, uint flags, DBUG_ENTER("open_and_process_table"); DEBUG_SYNC(thd, "open_and_process_table"); -#ifdef WITH_WSREP - WSREP_INFO("DEBUG: %s: table: %p name: %s db: %s flags: %u", __FUNCTION__, - tables, tables->table_name.str, - tables->db.str, tables->for_insert_data); - -#endif - /* Ignore placeholders for derived tables. After derived tables processing, link to created temporary table will be put here. @@ -4113,9 +4103,6 @@ lock_table_names(THD *thd, const DDL_options_st &options, MDL_STATEMENT); mdl_savepoint= thd->mdl_context.mdl_savepoint(); -#ifdef WITH_WSREP - WSREP_INFO("DEBUG: %s(%u)", __FUNCTION__, __LINE__); -#endif while (!thd->mdl_context.acquire_locks(&mdl_requests, lock_wait_timeout) && !upgrade_lock_if_not_exists(thd, options, tables_start, lock_wait_timeout) && @@ -4815,12 +4802,6 @@ bool DML_prelocking_strategy::handle_table(THD *thd, /* We rely on a caller to check that table is going to be changed. */ DBUG_ASSERT(table_list->lock_type >= TL_FIRST_WRITE || thd->lex->default_used); -#ifdef WITH_WSREP - WSREP_INFO("DEBUG: handle_table: table: %p name: %s db: %s flags: %u", - table_list, table_list->table_name.str, - table_list->db.str, table_list->for_insert_data); - -#endif if (table_list->trg_event_map) { diff --git a/sql/sql_show.cc b/sql/sql_show.cc index 20caaac62efad..40e8a800b2604 100644 --- a/sql/sql_show.cc +++ b/sql/sql_show.cc @@ -4899,9 +4899,6 @@ try_acquire_high_prio_shared_mdl_lock(THD *thd, TABLE_LIST *table, other locked tables, we prefer not to wait on a conflicting lock. */ -#ifdef WITH_WSREP - WSREP_INFO("DEBUG: %s(%u)", __FUNCTION__, __LINE__); -#endif error= thd->mdl_context.try_acquire_lock(&table->mdl_request); } else diff --git a/sql/wsrep_applier.cc b/sql/wsrep_applier.cc index 827e12eb8000d..8767f698bf2e6 100644 --- a/sql/wsrep_applier.cc +++ b/sql/wsrep_applier.cc @@ -213,9 +213,6 @@ int wsrep_apply_events(THD* thd, exec_res= ev->apply_event(thd->wsrep_rgi); DBUG_PRINT("info", ("exec_event result: %d", exec_res)); - WSREP_INFO("Event %d %s applied: rcode %d, seqno %lld", - event, ev->get_type_str(), exec_res, - (long long) wsrep_thd_trx_seqno(thd)); if (exec_res) { WSREP_WARN("Event %d %s apply failed: %d, seqno %lld", diff --git a/sql/wsrep_high_priority_service.cc b/sql/wsrep_high_priority_service.cc index 1be9912412f66..ecb0e487f2b37 100644 --- a/sql/wsrep_high_priority_service.cc +++ b/sql/wsrep_high_priority_service.cc @@ -125,7 +125,6 @@ static int apply_events(THD* thd, const wsrep::const_buffer& data, wsrep::mutable_buffer& err) { - WSREP_INFO("DEBUG: %s: thd = %llu", __FUNCTION__, thd->thread_id); int const ret= wsrep_apply_events(thd, rli, data.data(), data.size()); if (ret || wsrep_thd_has_ignored_error(thd)) { @@ -426,10 +425,6 @@ int Wsrep_high_priority_service::apply_toi(const wsrep::ws_meta& ws_meta, };); #endif - WSREP_INFO("DEBUG: %s: thd = %llu, ws seqno = %llu, flags = %s, client = %llu", - __FUNCTION__, thd->thread_id, ws_meta.seqno(), - wsrep::flags_to_string(ws_meta.flags()).c_str(), - ws_meta.client_id()); int ret= apply_events(thd, m_rli, data, err); wsrep_thd_set_ignored_error(thd, false); trans_commit(thd); @@ -597,10 +592,6 @@ int Wsrep_applier_service::apply_write_set(const wsrep::ws_meta& ws_meta, };); #endif /* ENABLED_DEBUG_SYNC */ - WSREP_INFO("DEBUG: %s: thd = %llu, ws seqno = %llu, flags = %s, client = %llu", - __FUNCTION__, thd->thread_id, ws_meta.seqno(), - wsrep::flags_to_string(ws_meta.flags()).c_str(), - ws_meta.client_id()); wsrep_setup_uk_and_fk_checks(thd); int ret= apply_events(thd, m_rli, data, err); diff --git a/sql/wsrep_mysqld.cc b/sql/wsrep_mysqld.cc index b7951fbfbede7..d48ad74d6fedd 100644 --- a/sql/wsrep_mysqld.cc +++ b/sql/wsrep_mysqld.cc @@ -2693,7 +2693,7 @@ static int wsrep_TOI_begin(THD *thd, const char *db, const char *table, { DBUG_ASSERT(wsrep_OSU_method_get(thd) == WSREP_OSU_TOI); - WSREP_INFO("TOI Begin: %s, fk_tables = %p", wsrep_thd_query(thd), fk_tables); + WSREP_DEBUG("TOI Begin: %s", wsrep_thd_query(thd)); if (wsrep_can_run_in_toi(thd, db, table, table_list, create_info) == false) { @@ -2738,14 +2738,6 @@ static int wsrep_TOI_begin(THD *thd, const char *db, const char *table, int ret= cs.enter_toi_local(key_array, wsrep::const_buffer(buff.ptr, buff.len)); - WSREP_INFO("DEBUG: %s(%u): ret = %d, #key_array = %u", __FUNCTION__, __LINE__, ret, - key_array.size() - ); - std::ostringstream ostream; - for (uint i = 0; i < key_array.size(); i++) { - ostream << "Key " << i << ":" << key_array[i] << ". "; - } - WSREP_INFO("DEBUG: %s(%u): keys: %s", __FUNCTION__, __LINE__, ostream.str().c_str()); if (ret) { @@ -2827,7 +2819,6 @@ static int wsrep_TOI_begin(THD *thd, const char *db, const char *table, if (rc) wsrep_TOI_begin_failed(thd, NULL); - WSREP_INFO("DEBUG: %s(%u): rc = %d", __FUNCTION__, __LINE__, rc); return rc; } @@ -2835,7 +2826,7 @@ static void wsrep_TOI_end(THD *thd) { wsrep_to_isolation--; wsrep::client_state& client_state(thd->wsrep_cs()); DBUG_ASSERT(wsrep_thd_is_local_toi(thd)); - WSREP_INFO("TO END: %lld: %s", client_state.toi_meta().seqno().get(), + WSREP_DEBUG("TO END: %lld: %s", client_state.toi_meta().seqno().get(), wsrep_thd_query(thd)); wsrep_gtid_server.signal_waiters(thd->wsrep_current_gtid_seqno, false); From 4e785bd2048237fda256b5f7d13323a3b305c0f8 Mon Sep 17 00:00:00 2001 From: Pekka Lampio Date: Mon, 3 Jun 2024 10:39:22 +0300 Subject: [PATCH 3/6] Fixes for issues raised by the reviewers. --- mysql-test/suite/galera/r/MDEV-28452.result | 17 +++----------- mysql-test/suite/galera/t/MDEV-28452.test | 25 +++++++-------------- sql/sql_admin.cc | 3 --- 3 files changed, 11 insertions(+), 34 deletions(-) diff --git a/mysql-test/suite/galera/r/MDEV-28452.result b/mysql-test/suite/galera/r/MDEV-28452.result index c55adc58f7671..4db16ee0ee6eb 100644 --- a/mysql-test/suite/galera/r/MDEV-28452.result +++ b/mysql-test/suite/galera/r/MDEV-28452.result @@ -9,12 +9,7 @@ CREATE TABLE `user` ( `password` char(60) COLLATE utf8mb4_unicode_ci NOT NULL, `status` enum('sign_up','invited','active','archived') COLLATE utf8mb4_unicode_ci NOT NULL DEFAULT 'invited', -`token` char(64) COLLATE utf8mb4_unicode_ci DEFAULT NULL, -`token_valid_till` datetime DEFAULT NULL, `last_login` datetime DEFAULT NULL, -`password_updated_at` datetime DEFAULT NULL, -`created_at` timestamp NULL DEFAULT NULL, -`updated_at` timestamp NULL DEFAULT NULL, PRIMARY KEY (`id`), UNIQUE KEY `user_username_unique` (`username`), KEY `user_environment_id_index` (`environment_id`) @@ -29,19 +24,15 @@ COLLATE utf8mb4_unicode_ci NOT NULL DEFAULT 'unknown', `value` varchar(255) CHARACTER SET utf8mb4 COLLATE utf8mb4_bin NOT NULL, `user_id` char(36) COLLATE utf8mb4_unicode_ci DEFAULT NULL, `date` date NOT NULL, -`count` int(10) unsigned NOT NULL, -`created_at` timestamp NULL DEFAULT NULL, -`updated_at` timestamp NULL DEFAULT NULL, PRIMARY KEY (`type`,`status`,`origin`,`ip`,`value`,`date`), KEY `log_history_daily_user_id_foreign` (`user_id`), CONSTRAINT `log_history_daily_user_id_foreign` FOREIGN KEY (`user_id`) REFERENCES `user` (`id`) ON DELETE SET NULL ON UPDATE CASCADE ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci; SET SESSION autocommit = 0; -INSERT INTO `user` VALUES ("id_1", "abc", "user 1", "secret", "active", -NULL, NULL, NULL, NULL, NULL, NULL); +INSERT INTO `user` VALUES ("id_1", "abc", "user 1", "secret", "active", NULL); INSERT INTO `log_history_daily` VALUES ("user", "valid", "unknown", -"192.168.0.1", "Sample", "id_1", "2024-04-22", 1, NULL, NULL); +"192.168.0.1", "Sample", "id_1", "2024-04-22"); COMMIT; connection node_2; SET GLOBAL wsrep_slave_threads = 2; @@ -49,14 +40,12 @@ SELECT @@wsrep_slave_threads; @@wsrep_slave_threads 2 SET GLOBAL debug_dbug = "+d,sync.mdev_28452"; -connect node_1a, 127.0.0.1, root, , test, $NODE_MYPORT_1; -connection node_1a; +connection node_1; OPTIMIZE TABLE `log_history_daily`; Table Op Msg_type Msg_text test.log_history_daily optimize note Table does not support optimize, doing recreate + analyze instead test.log_history_daily optimize status OK COMMIT; -connection node_1; UPDATE `user` SET `last_login` = '2024-04-23' WHERE `id`="id_1"; COMMIT; connection node_2a; diff --git a/mysql-test/suite/galera/t/MDEV-28452.test b/mysql-test/suite/galera/t/MDEV-28452.test index b53bf344e6553..5b8ac4ab7fd20 100644 --- a/mysql-test/suite/galera/t/MDEV-28452.test +++ b/mysql-test/suite/galera/t/MDEV-28452.test @@ -18,12 +18,7 @@ CREATE TABLE `user` ( `password` char(60) COLLATE utf8mb4_unicode_ci NOT NULL, `status` enum('sign_up','invited','active','archived') COLLATE utf8mb4_unicode_ci NOT NULL DEFAULT 'invited', - `token` char(64) COLLATE utf8mb4_unicode_ci DEFAULT NULL, - `token_valid_till` datetime DEFAULT NULL, `last_login` datetime DEFAULT NULL, - `password_updated_at` datetime DEFAULT NULL, - `created_at` timestamp NULL DEFAULT NULL, - `updated_at` timestamp NULL DEFAULT NULL, PRIMARY KEY (`id`), UNIQUE KEY `user_username_unique` (`username`), KEY `user_environment_id_index` (`environment_id`) @@ -40,9 +35,6 @@ CREATE TABLE `log_history_daily` ( `value` varchar(255) CHARACTER SET utf8mb4 COLLATE utf8mb4_bin NOT NULL, `user_id` char(36) COLLATE utf8mb4_unicode_ci DEFAULT NULL, `date` date NOT NULL, - `count` int(10) unsigned NOT NULL, - `created_at` timestamp NULL DEFAULT NULL, - `updated_at` timestamp NULL DEFAULT NULL, PRIMARY KEY (`type`,`status`,`origin`,`ip`,`value`,`date`), KEY `log_history_daily_user_id_foreign` (`user_id`), CONSTRAINT `log_history_daily_user_id_foreign` FOREIGN KEY (`user_id`) @@ -52,10 +44,9 @@ CREATE TABLE `log_history_daily` ( SET SESSION autocommit = 0; # insert one row in each table -INSERT INTO `user` VALUES ("id_1", "abc", "user 1", "secret", "active", - NULL, NULL, NULL, NULL, NULL, NULL); +INSERT INTO `user` VALUES ("id_1", "abc", "user 1", "secret", "active", NULL); INSERT INTO `log_history_daily` VALUES ("user", "valid", "unknown", - "192.168.0.1", "Sample", "id_1", "2024-04-22", 1, NULL, NULL); + "192.168.0.1", "Sample", "id_1", "2024-04-22"); COMMIT; # Start two slave threads in node 2. @@ -67,16 +58,13 @@ SET GLOBAL wsrep_slave_threads = 2; SELECT @@wsrep_slave_threads; SET GLOBAL debug_dbug = "+d,sync.mdev_28452"; -# Run two transactions in parallel in node 1: +# Run two transactions sequentially on node 1: # 1) OPTIMIZE TABLE on the child table of the foreign key constraint, ---connect node_1a, 127.0.0.1, root, , test, $NODE_MYPORT_1 ---connection node_1a ---sleep 5 +--connection node_1 OPTIMIZE TABLE `log_history_daily`; COMMIT; # 2) and UPDATE on the parent table of the foreign key constraint. ---connection node_1 # update the row in "user" so that it affects the foreign key in # "log_history_daily" UPDATE `user` SET `last_login` = '2024-04-23' WHERE `id`="id_1"; @@ -89,9 +77,12 @@ SET GLOBAL debug_dbug = 'RESET'; SET DEBUG_SYNC = 'now SIGNAL signal.mdev_28452'; SET DEBUG_SYNC = 'RESET'; +# wait till the UPDATE has finished on node 2 +--let $wait_condition = SELECT COUNT(*) > 0 FROM `user` WHERE `last_login` = '2024-04-23' +--source include/wait_condition.inc + # cleanup --connection node_1 ---sleep 5 DROP TABLE `log_history_daily`; DROP TABLE `user`; --connection node_2 diff --git a/sql/sql_admin.cc b/sql/sql_admin.cc index be6df8b72f3f4..4e9127a760a35 100644 --- a/sql/sql_admin.cc +++ b/sql/sql_admin.cc @@ -1638,8 +1638,6 @@ bool Sql_cmd_optimize_table::execute(THD *thd) } } } -#else - WSREP_TO_ISOLATION_BEGIN_WRTCHK(NULL, NULL, first_table); #endif /* WITH_WSREP */ res= (specialflag & SPECIAL_NO_NEW_FUNC) ? mysql_recreate_table(thd, first_table, &recreate_info, true) : @@ -1648,7 +1646,6 @@ bool Sql_cmd_optimize_table::execute(THD *thd) &handler::ha_optimize, 0, true); m_lex->first_select_lex()->table_list.first= first_table; m_lex->query_tables= first_table; - error: DBUG_RETURN(res); } From 827d90d75756126b61209818957d0bdf7de16b64 Mon Sep 17 00:00:00 2001 From: Pekka Lampio Date: Mon, 10 Jun 2024 11:41:18 +0300 Subject: [PATCH 4/6] Improved MTR test MDEV-28452 by removing a sleep. --- mysql-test/suite/galera/t/MDEV-28452.test | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/mysql-test/suite/galera/t/MDEV-28452.test b/mysql-test/suite/galera/t/MDEV-28452.test index 5b8ac4ab7fd20..d0a5be810b860 100644 --- a/mysql-test/suite/galera/t/MDEV-28452.test +++ b/mysql-test/suite/galera/t/MDEV-28452.test @@ -41,6 +41,7 @@ CREATE TABLE `log_history_daily` ( REFERENCES `user` (`id`) ON DELETE SET NULL ON UPDATE CASCADE ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_unicode_ci; + SET SESSION autocommit = 0; # insert one row in each table @@ -72,7 +73,10 @@ COMMIT; # allow the stopped OPTIMIZE TABLE transaction to proceed --connection node_2a ---sleep 5 + +# wait till debug sync point has been set on node 2 +#--sleep 5 + SET GLOBAL debug_dbug = 'RESET'; SET DEBUG_SYNC = 'now SIGNAL signal.mdev_28452'; SET DEBUG_SYNC = 'RESET'; From d20fcad63e7450de811f2bf95cad8f6c11a1fd24 Mon Sep 17 00:00:00 2001 From: Pekka Lampio Date: Mon, 17 Jun 2024 14:29:12 +0300 Subject: [PATCH 5/6] Improved synchronization in the MTR test MDEV-28452. --- mysql-test/suite/galera/r/MDEV-28452.result | 1 + mysql-test/suite/galera/t/MDEV-28452.test | 2 +- sql/mdl.cc | 4 ++-- 3 files changed, 4 insertions(+), 3 deletions(-) diff --git a/mysql-test/suite/galera/r/MDEV-28452.result b/mysql-test/suite/galera/r/MDEV-28452.result index 4db16ee0ee6eb..796ed6060382f 100644 --- a/mysql-test/suite/galera/r/MDEV-28452.result +++ b/mysql-test/suite/galera/r/MDEV-28452.result @@ -49,6 +49,7 @@ COMMIT; UPDATE `user` SET `last_login` = '2024-04-23' WHERE `id`="id_1"; COMMIT; connection node_2a; +SET DEBUG_SYNC='NOW WAIT_FOR mdev_28452_reached'; SET GLOBAL debug_dbug = 'RESET'; SET DEBUG_SYNC = 'now SIGNAL signal.mdev_28452'; SET DEBUG_SYNC = 'RESET'; diff --git a/mysql-test/suite/galera/t/MDEV-28452.test b/mysql-test/suite/galera/t/MDEV-28452.test index d0a5be810b860..34b507c55559d 100644 --- a/mysql-test/suite/galera/t/MDEV-28452.test +++ b/mysql-test/suite/galera/t/MDEV-28452.test @@ -75,7 +75,7 @@ COMMIT; --connection node_2a # wait till debug sync point has been set on node 2 -#--sleep 5 +SET DEBUG_SYNC='NOW WAIT_FOR mdev_28452_reached'; SET GLOBAL debug_dbug = 'RESET'; SET DEBUG_SYNC = 'now SIGNAL signal.mdev_28452'; diff --git a/sql/mdl.cc b/sql/mdl.cc index fb6c5a592f271..ebc89aaea0a94 100644 --- a/sql/mdl.cc +++ b/sql/mdl.cc @@ -2315,8 +2315,8 @@ MDL_context::acquire_lock(MDL_request *mdl_request, double lock_wait_timeout) DBUG_EXECUTE_IF("sync.mdev_28452", { const char act[]= - "now " - "wait_for signal.mdev_28452"; + "NOW SIGNAL mdev_28452_reached " + "WAIT_FOR signal.mdev_28452"; DBUG_ASSERT(!debug_sync_set_action(get_thd(), STRING_WITH_LEN(act))); };); From a9adda401f65258c44f9a9441fe89a07584d5d39 Mon Sep 17 00:00:00 2001 From: Pekka Lampio Date: Mon, 17 Jun 2024 14:55:24 +0300 Subject: [PATCH 6/6] Improve Sql_cmd_optimize_table::execute(). --- sql/sql_admin.cc | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/sql/sql_admin.cc b/sql/sql_admin.cc index 4e9127a760a35..0b5966c9f26c2 100644 --- a/sql/sql_admin.cc +++ b/sql/sql_admin.cc @@ -1627,7 +1627,8 @@ bool Sql_cmd_optimize_table::execute(THD *thd) } wsrep::key_array keys; - if (!wsrep_append_fk_parent_table(thd, first_table, &keys)) + if (wsrep_thd_is_local(thd) && + !wsrep_append_fk_parent_table(thd, first_table, &keys)) { WSREP_TO_ISOLATION_BEGIN_ALTER(first_table->db.str, first_table->table_name.str,