From 3858061dacc232a3dcd566ea5aff7fc5fc232bb0 Mon Sep 17 00:00:00 2001 From: Robert Golebiowski Date: Sun, 5 Mar 2017 21:24:56 +0100 Subject: [PATCH] Bug #84415 slave don't report Seconds_Behind_Master when running slave_parallel_workers > 0 The fix: When a task from GAQ finishes executing, last_master_timestamp gets assigned timestamp from next task in GAQ. In case GAQ is empty last_master_timestamp gets reset to 0. Because last_master_timestamp is only re-assigned when task leaves GAQ it must be also assigned when first event (from parallel execution) arrives. --- mysql-test/include/wait_for_mts_checkpoint.inc | 11 + mysql-test/suite/rpl/r/bug84415.result | 108 +++++++++ mysql-test/suite/rpl/t/bug84415.test | 291 +++++++++++++++++++++++++ sql/log_event.cc | 6 +- sql/rpl_rli.cc | 7 +- sql/rpl_rli.h | 3 +- sql/rpl_rli_pdb.cc | 8 +- sql/rpl_rli_pdb.h | 1 + sql/rpl_slave.cc | 40 +++- 9 files changed, 454 insertions(+), 21 deletions(-) create mode 100644 mysql-test/include/wait_for_mts_checkpoint.inc create mode 100644 mysql-test/suite/rpl/r/bug84415.result create mode 100644 mysql-test/suite/rpl/t/bug84415.test diff --git a/mysql-test/include/wait_for_mts_checkpoint.inc b/mysql-test/include/wait_for_mts_checkpoint.inc new file mode 100644 index 0000000..e7b29c6 --- /dev/null +++ b/mysql-test/include/wait_for_mts_checkpoint.inc @@ -0,0 +1,11 @@ +# ==== Purpose ==== +# +# Waits until mts_checkpoint_routine has been fully +# executed - from the beginning till the end +# +SET @@global.debug= "+d,mts_checkpoint"; +#If end was hit before start - clear it +SET DEBUG_SYNC="RESET"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_start"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_end"; +SET @@global.debug= "-d,mts_checkpoint"; diff --git a/mysql-test/suite/rpl/r/bug84415.result b/mysql-test/suite/rpl/r/bug84415.result new file mode 100644 index 0000000..f2d1737 --- /dev/null +++ b/mysql-test/suite/rpl/r/bug84415.result @@ -0,0 +1,108 @@ +include/master-slave.inc +Warnings: +Note #### Sending passwords in plain text without SSL/TLS is extremely insecure. +Note #### Storing MySQL user name or password information in the master info repository is not secure and is therefore not recommended. Please consider using the USER and PASSWORD connection options for START SLAVE; see the 'START SLAVE Syntax' in the MySQL Manual for more information. +[connection master] +# +# Bug #84415: slave don't report Seconds_Behind_Master when +# running slave_parallel_workers > 0 +# +SET @@global.debug= "+d,dbug.mts.force_clock_diff_eq_0"; +SET @save.slave_parallel_workers= @@global.slave_parallel_workers; +SET @save_slave_transaction_retries= @@global.slave_transaction_retries; +SET @@global.slave_transaction_retries= 0; +SET @@global.slave_parallel_workers= 4; +include/start_slave.inc +CREATE TABLE t1 (f1 INT); +CREATE DATABASE test2; +USE test2; +CREATE TABLE t2 (f1 INT); +include/sync_slave_sql_with_master.inc +LOCK TABLE test.t1 WRITE; +LOCK TABLE test2.t2 WRITE; +USE test; +INSERT INTO t1 VALUES (1); +USE test2; +INSERT INTO t2 VALUES (1); +include/sync_slave_io_with_master.inc +SET @@global.debug= "+d,mts_checkpoint"; +SET DEBUG_SYNC="RESET"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_start"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_end"; +SET @@global.debug= "-d,mts_checkpoint"; +include/assert.inc [Seconds_Behind_Master must be between 5 and upper_bound] +UNLOCK TABLES; +SET @@global.debug= "+d,mts_checkpoint"; +SET DEBUG_SYNC="RESET"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_start"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_end"; +SET @@global.debug= "-d,mts_checkpoint"; +include/assert.inc [Seconds_Behind_Master must be between 2 and upper_bound] +UNLOCK TABLES; +include/sync_slave_sql_with_master.inc +SET @@global.debug= "+d,mts_checkpoint"; +SET DEBUG_SYNC="RESET"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_start"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_end"; +SET @@global.debug= "-d,mts_checkpoint"; +include/assert.inc [Seconds_Behind_Master must be 0] +LOCK TABLE test2.t2 WRITE; +USE test; +INSERT INTO t1 VALUES (1); +USE test2; +INSERT INTO t2 VALUES (1); +include/sync_slave_io_with_master.inc +SET @@global.debug= "+d,mts_checkpoint"; +SET DEBUG_SYNC="RESET"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_start"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_end"; +SET @@global.debug= "-d,mts_checkpoint"; +include/assert.inc [Seconds_Behind_Master must be between 2 and upper_bound] +UNLOCK TABLES; +SET @@global.debug= "+d,mts_checkpoint"; +SET DEBUG_SYNC="RESET"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_start"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_end"; +SET @@global.debug= "-d,mts_checkpoint"; +include/assert.inc [Seconds_Behind_Master must be 0] +CREATE DATABASE test3; +USE test3; +CREATE TABLE t3 (f1 INT); +include/sync_slave_sql_with_master.inc +LOCK TABLE test.t1 WRITE; +LOCK TABLE test3.t3 WRITE; +USE test; +INSERT INTO t1 VALUES (1); +use test2; +INSERT INTO t2 VALUES (1); +USE test3; +INSERT INTO t3 VALUES (1); +include/sync_slave_io_with_master.inc +SET @@global.debug= "+d,mts_checkpoint"; +SET DEBUG_SYNC="RESET"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_start"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_end"; +SET @@global.debug= "-d,mts_checkpoint"; +include/assert.inc [Seconds_Behind_Master must be between 7 and upper_bound] +UNLOCK TABLES; +SET @@global.debug= "+d,mts_checkpoint"; +SET DEBUG_SYNC="RESET"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_start"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_end"; +SET @@global.debug= "-d,mts_checkpoint"; +include/assert.inc [Seconds_Behind_Master must be between 2 and upper_bound] +UNLOCK TABLES; +SET @@global.debug= "+d,mts_checkpoint"; +SET DEBUG_SYNC="RESET"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_start"; +SET DEBUG_SYNC="now WAIT_FOR mts_checkpoint_end"; +SET @@global.debug= "-d,mts_checkpoint"; +include/assert.inc [Seconds_Behind_Master must be 0] +DROP TABLE test.t1; +DROP DATABASE test2; +DROP DATABASE test3; +include/sync_slave_sql_with_master.inc +SET @@global.slave_parallel_workers= @save.slave_parallel_workers; +SET @@global.debug= "-d,dbug.mts.force_clock_diff_eq_0"; +SET @@global.slave_transaction_retries= @save_slave_transaction_retries; +include/rpl_end.inc diff --git a/mysql-test/suite/rpl/t/bug84415.test b/mysql-test/suite/rpl/t/bug84415.test new file mode 100644 index 0000000..752e1a0 --- /dev/null +++ b/mysql-test/suite/rpl/t/bug84415.test @@ -0,0 +1,291 @@ +--source include/have_debug.inc +--source include/have_debug_sync.inc +--let $rpl_skip_start_slave= 1 +--source include/master-slave.inc + +--echo # +--echo # Bug #84415: slave don't report Seconds_Behind_Master when +--echo # running slave_parallel_workers > 0 +--echo # + +# restart slave in MTS mode +connection slave; +SET @@global.debug= "+d,dbug.mts.force_clock_diff_eq_0"; +SET @save.slave_parallel_workers= @@global.slave_parallel_workers; +SET @save_slave_transaction_retries= @@global.slave_transaction_retries; +SET @@global.slave_transaction_retries= 0; +SET @@global.slave_parallel_workers= 4; +--source include/start_slave.inc + +# 1st scenario. slave executes insert to t1 and is blocked due to lock on t1, after 3s another worker +# on slave starts to execute insert to t2, this worker is also blocked on insert to t2. After 2 more +# seconds we check Seconds_Behind_Master. Since worker is still executing insert to t1 this means +# that slave is at least 5s behind master (might be more due to slow network connection). + +connect (slave2,127.0.0.1,root,,test,$SLAVE_MYPORT,); +connection master; + +CREATE TABLE t1 (f1 INT); +CREATE DATABASE test2; +USE test2; +CREATE TABLE t2 (f1 INT); +--source include/sync_slave_sql_with_master.inc + +connection slave1; +LOCK TABLE test.t1 WRITE; + +connection slave2; +LOCK TABLE test2.t2 WRITE; + +connection master; + +USE test; +let $start= `SELECT UNIX_TIMESTAMP()`; +INSERT INTO t1 VALUES (1); + +--real_sleep 3 + +USE test2; +let $start2= `SELECT UNIX_TIMESTAMP()`; +INSERT INTO t2 VALUES (1); +--real_sleep 2 + +# +# all events are in relay-log +# +source include/sync_slave_io_with_master.inc; + +# Check that two workers are waiting +let $wait_condition= SELECT count(*) = 2 FROM INFORMATION_SCHEMA.PROCESSLIST WHERE State = 'Waiting for table metadata lock'; +--source include/wait_condition.inc +let $wait_condition= SELECT count(*) = 0 FROM INFORMATION_SCHEMA.PROCESSLIST WHERE State = 'Executing event' + OR State = 'update'; +--source include/wait_condition.inc + +# $upper_bound = "timestamp on slave after reading Seconds_Behind_Master" - +# "timestamp on master before the insert statement". + +source include/wait_for_mts_checkpoint.inc; + +let $sbm= query_get_value("SHOW SLAVE STATUS", Seconds_Behind_Master, 1); +let $stop= `SELECT UNIX_TIMESTAMP()`; +let $upper_bound= `SELECT $stop - $start`; +let $assert_text= Seconds_Behind_Master must be between 5 and upper_bound; +let $assert_cond= 5 <= $sbm AND $sbm <= $upper_bound; +source include/assert.inc; + +connection slave1; +UNLOCK TABLES; + +# Now the first worker which was 5s behind the master has completed its task. However the second +# worker is still running its task. This means that Seconds_Behind_Master should now be 2s +# or slightly more. + +# Check that one worker is still running (waiting) +let $wait_condition= SELECT count(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST WHERE State = 'Waiting for table metadata lock'; +--source include/wait_condition.inc +let $wait_condition= SELECT count(*) = 0 FROM INFORMATION_SCHEMA.PROCESSLIST WHERE State = 'Executing event' + OR State = 'update'; +--source include/wait_condition.inc + +source include/wait_for_mts_checkpoint.inc; + +let $sbm= query_get_value("SHOW SLAVE STATUS", Seconds_Behind_Master, 1); +let $stop= `SELECT UNIX_TIMESTAMP()`; +let $upper_bound= `SELECT $stop - $start2`; +let $assert_text= Seconds_Behind_Master must be between 2 and upper_bound; +let $assert_cond= 2 <= $sbm AND $sbm <= $upper_bound; +source include/assert.inc; + +connection slave2; +UNLOCK TABLES; + +--connection master +--source include/sync_slave_sql_with_master.inc + +# Now both workers have completed their tasks and no new tasks have arrived, thus +# Seconds_Behind_Master should be equal to 0. + +let $wait_condition= SELECT count(*) = 0 FROM INFORMATION_SCHEMA.PROCESSLIST WHERE State = 'Waiting for table metadata lock'; +source include/wait_for_mts_checkpoint.inc; +let $wait_condition= SELECT count(*) = 0 FROM INFORMATION_SCHEMA.PROCESSLIST WHERE State = 'Executing event' + OR State = 'update'; +--source include/wait_condition.inc + +let $sbm= query_get_value("SHOW SLAVE STATUS", Seconds_Behind_Master, 1); +let $assert_text= Seconds_Behind_Master must be 0; +let $assert_cond= $sbm = 0; +source include/assert.inc; + +# 2nd scenario. In this scenario we check if Seconds_Behind_Master is updated correctly when first +# worker compeletes its tasks first. + +connection slave2; +LOCK TABLE test2.t2 WRITE; + +connection master; + +USE test; +let $start= `SELECT UNIX_TIMESTAMP()`; +INSERT INTO t1 VALUES (1); + +--real_sleep 3 + +USE test2; +let $start2= `SELECT UNIX_TIMESTAMP()`; +INSERT INTO t2 VALUES (1); +--real_sleep 2 + +# +# all events are in relay-log +# +source include/sync_slave_io_with_master.inc; + +# Check that one worker is still running +let $wait_condition= SELECT count(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST WHERE State = 'Waiting for table metadata lock'; +--source include/wait_condition.inc +let $wait_condition= SELECT count(*) = 0 FROM INFORMATION_SCHEMA.PROCESSLIST WHERE State = 'Executing event' + OR State = 'update'; +--source include/wait_condition.inc + +# First worker has completed its task, second one is still running. +# We should be 2 seconds behind the master. + +source include/wait_for_mts_checkpoint.inc; + +let $sbm= query_get_value("SHOW SLAVE STATUS", Seconds_Behind_Master, 1); +let $stop= `SELECT UNIX_TIMESTAMP()`; +let $upper_bound= `SELECT $stop - $start2`; +let $assert_text= Seconds_Behind_Master must be between 2 and upper_bound; +let $assert_cond= 2 <= $sbm AND $sbm <= $upper_bound; +source include/assert.inc; + +connection slave2; +UNLOCK TABLES; + +let $wait_condition= SELECT count(*) = 0 FROM INFORMATION_SCHEMA.PROCESSLIST WHERE State = 'Waiting for table metadata lock'; +--source include/wait_condition.inc +let $wait_condition= SELECT count(*) = 0 FROM INFORMATION_SCHEMA.PROCESSLIST WHERE State = 'Executing event' + OR State = 'update'; +--source include/wait_condition.inc + +# Now both workers have completed their tasks and no new tasks have arrived, thus +# Seconds_Behind_Master should be equal to 0. + +source include/wait_for_mts_checkpoint.inc; + +let $sbm= query_get_value("SHOW SLAVE STATUS", Seconds_Behind_Master, 1); +let $assert_text= Seconds_Behind_Master must be 0; +let $assert_cond= $sbm = 0; +source include/assert.inc; + +# 3rd scenario. Three workers are running. In this scenario we check if correct Seconds_Behind_Master +# is calculated when second worker completes first. + +--connection master + +CREATE DATABASE test3; +USE test3; +CREATE TABLE t3 (f1 INT); +--source include/sync_slave_sql_with_master.inc + +connect (slave3,127.0.0.1,root,,test,$SLAVE_MYPORT,); + +connection slave1; +LOCK TABLE test.t1 WRITE; + +connection slave3; +LOCK TABLE test3.t3 WRITE; + +connection master; + +let $start= `SELECT UNIX_TIMESTAMP()`; + +USE test; +INSERT INTO t1 VALUES (1); +--real_sleep 3 + +use test2; +INSERT INTO t2 VALUES (1); +--real_sleep 2 + +USE test3; +let $start3= `SELECT UNIX_TIMESTAMP()`; +INSERT INTO t3 VALUES (1); +--real_sleep 2 + +source include/sync_slave_io_with_master.inc; + +# Only second worker has completed. This means that longest running worker is the first one, thus +# slave should be 7s behind the master. + +# Check that two workers are still running +let $wait_condition= SELECT count(*) = 2 FROM INFORMATION_SCHEMA.PROCESSLIST WHERE State = 'Waiting for table metadata lock'; +--source include/wait_condition.inc +let $wait_condition= SELECT count(*) = 0 FROM INFORMATION_SCHEMA.PROCESSLIST WHERE State = 'Executing event' + OR State = 'update'; +--source include/wait_condition.inc + +source include/wait_for_mts_checkpoint.inc; + +let $sbm= query_get_value("SHOW SLAVE STATUS", Seconds_Behind_Master, 1); +let $stop= `SELECT UNIX_TIMESTAMP()`; +let $upper_bound= `SELECT $stop - $start`; +let $assert_text= Seconds_Behind_Master must be between 7 and upper_bound; +let $assert_cond= 7 <= $sbm AND $sbm <= $upper_bound; +source include/assert.inc; + +connection slave1; +UNLOCK TABLES; + +# Check that last worker is still running +let $wait_condition= SELECT count(*) = 1 FROM INFORMATION_SCHEMA.PROCESSLIST WHERE State = 'Waiting for table metadata lock'; +--source include/wait_condition.inc +let $wait_condition= SELECT count(*) = 0 FROM INFORMATION_SCHEMA.PROCESSLIST WHERE State = 'Executing event' + OR State = 'update'; +--source include/wait_condition.inc + +source include/wait_for_mts_checkpoint.inc; + +let $sbm= query_get_value("SHOW SLAVE STATUS", Seconds_Behind_Master, 1); +let $stop= `SELECT UNIX_TIMESTAMP()`; +let $upper_bound= `SELECT $stop - $start3`; +let $assert_text= Seconds_Behind_Master must be between 2 and upper_bound; +let $assert_cond= 2 <= $sbm AND $sbm <= $upper_bound; +source include/assert.inc; + +connection slave3; +UNLOCK TABLES; + +# Now all three workers have completed. Seconds_Behind_Master should be 0. + +let $wait_condition= SELECT count(*) = 0 FROM INFORMATION_SCHEMA.PROCESSLIST WHERE State = 'Waiting for table metadata lock'; +--source include/wait_condition.inc +let $wait_condition= SELECT count(*) = 0 FROM INFORMATION_SCHEMA.PROCESSLIST WHERE State = 'Executing event' + OR State = 'update'; +--source include/wait_condition.inc + + +source include/wait_for_mts_checkpoint.inc; + +let $sbm= query_get_value("SHOW SLAVE STATUS", Seconds_Behind_Master, 1); +let $assert_text= Seconds_Behind_Master must be 0; +let $assert_cond= $sbm = 0; +source include/assert.inc; + +## +# cleanup +## +connection master; +DROP TABLE test.t1; +DROP DATABASE test2; +DROP DATABASE test3; + +--source include/sync_slave_sql_with_master.inc + +SET @@global.slave_parallel_workers= @save.slave_parallel_workers; +SET @@global.debug= "-d,dbug.mts.force_clock_diff_eq_0"; +SET @@global.slave_transaction_retries= @save_slave_transaction_retries; + +--source include/rpl_end.inc + diff --git a/sql/log_event.cc b/sql/log_event.cc index a083745..0a58f83 100644 --- a/sql/log_event.cc +++ b/sql/log_event.cc @@ -6937,10 +6937,12 @@ int Rotate_log_event::do_update_pos(Relay_log_info *rli) (ulong) rli->get_group_master_log_pos())); mysql_mutex_unlock(&rli->data_lock); if (rli->is_parallel_exec()) + { + time_t ts= when.tv_sec + static_cast(exec_time); rli->reset_notified_checkpoint(0, - server_id ? when.tv_sec + (time_t) exec_time : 0, + server_id ? &ts : NULL, true/*need_data_lock=true*/); - + } /* Reset thd->variables.option_bits and sql_mode etc, because this could be the signal of a master's downgrade from 5.0 to 4.0. diff --git a/sql/rpl_rli.cc b/sql/rpl_rli.cc index 08593b8..3135e2e 100644 --- a/sql/rpl_rli.cc +++ b/sql/rpl_rli.cc @@ -222,10 +222,11 @@ void Relay_log_info::reset_notified_relay_log_change() @param shift number of bits to shift by Worker due to the current checkpoint change. @param new_ts new seconds_behind_master timestamp value - unless zero. Zero could be due to FD event. + unless NULL. NULL could be due to FD event. @param need_data_lock False if caller has locked @c data_lock */ -void Relay_log_info::reset_notified_checkpoint(ulong shift, time_t new_ts, +void Relay_log_info::reset_notified_checkpoint(ulong shift, + const time_t *const new_ts, bool need_data_lock) { /* @@ -277,7 +278,7 @@ void Relay_log_info::reset_notified_checkpoint(ulong shift, time_t new_ts, mysql_mutex_lock(&data_lock); else mysql_mutex_assert_owner(&data_lock); - last_master_timestamp= new_ts; + last_master_timestamp= *new_ts; if (need_data_lock) mysql_mutex_unlock(&data_lock); } diff --git a/sql/rpl_rli.h b/sql/rpl_rli.h index 678d30e..a720a2c 100644 --- a/sql/rpl_rli.h +++ b/sql/rpl_rli.h @@ -650,7 +650,8 @@ class Relay_log_info : public Rpl_info Coordinator notifies Workers about this event. Coordinator and Workers maintain a bitmap of executed group that is reset with a new checkpoint. */ - void reset_notified_checkpoint(ulong, time_t, bool); + void reset_notified_checkpoint(ulong, const time_t *const new_ts, + bool); /** Called when gaps execution is ended so it is crash-safe diff --git a/sql/rpl_rli_pdb.cc b/sql/rpl_rli_pdb.cc index 2c2e134..9827db9 100644 --- a/sql/rpl_rli_pdb.cc +++ b/sql/rpl_rli_pdb.cc @@ -1394,16 +1394,12 @@ ulong circular_buffer_queue::en_queue(void *item) void* circular_buffer_queue::head_queue() { - uchar *ret= NULL; if (entry == size) { DBUG_ASSERT(len == 0); + return NULL; } - else - { - get_dynamic(&Q, (uchar*) ret, entry); - } - return (void*) ret; + return dynamic_array_ptr(&Q, entry); } /** diff --git a/sql/rpl_rli_pdb.h b/sql/rpl_rli_pdb.h index c85865a..1aa8261 100644 --- a/sql/rpl_rli_pdb.h +++ b/sql/rpl_rli_pdb.h @@ -200,6 +200,7 @@ typedef struct st_slave_job_group checkpoint_relay_log_pos= 0; checkpoint_seqno= (uint) -1; done= 0; + ts= 0; #ifndef DBUG_OFF notified= false; #endif diff --git a/sql/rpl_slave.cc b/sql/rpl_slave.cc index 4a2d1d4..099d514 100644 --- a/sql/rpl_slave.cc +++ b/sql/rpl_slave.cc @@ -2270,6 +2270,8 @@ static int get_master_version_and_clock(MYSQL* mysql, Master_info* mi) mysql_mutex_lock(&mi->data_lock); mi->clock_diff_with_master= (long) (time((time_t*) 0) - strtoul(master_row[0], 0, 10)); + DBUG_EXECUTE_IF("dbug.mts.force_clock_diff_eq_0", + mi->clock_diff_with_master= 0;); mysql_mutex_unlock(&mi->data_lock); } else if (check_io_slave_killed(mi->info_thd, mi, NULL)) @@ -4352,11 +4354,17 @@ static int exec_relay_log_event(THD* thd, Relay_log_info* rli) If it is an artificial event, or a relay log event (IO thread generated event) or ev->when is set to 0, or a FD from master, or a heartbeat event with server_id '0' then we don't update the last_master_timestamp. + + In case of parallel execution last_master_timestamp is only updated when + an event is taken out of GAQ. Thus when last_master_timestamp is 0 we need + to initialize it with a timestamp from the first event to be executed in + parallel. */ - if (!(rli->is_parallel_exec() || - ev->is_artificial_event() || ev->is_relay_log_event() || - ev->when.tv_sec == 0 || ev->get_type_code() == FORMAT_DESCRIPTION_EVENT || - ev->server_id == 0)) + if ((!rli->is_parallel_exec() || rli->last_master_timestamp == 0) && + !(ev->is_artificial_event() || ev->is_relay_log_event() || + ev->when.tv_sec == 0 || + ev->get_type_code() == FORMAT_DESCRIPTION_EVENT || + ev->server_id == 0)) { rli->last_master_timestamp= ev->when.tv_sec + (time_t) ev->exec_time; DBUG_ASSERT(rli->last_master_timestamp >= 0); @@ -5659,6 +5667,7 @@ bool mts_checkpoint_routine(Relay_log_info *rli, ulonglong period, ulong cnt; bool error= FALSE; struct timespec curr_clock; + time_t ts=0; DBUG_ENTER("checkpoint_routine"); @@ -5668,6 +5677,13 @@ bool mts_checkpoint_routine(Relay_log_info *rli, ulonglong period, if (!rli->gaq->count_done(rli)) DBUG_RETURN(FALSE); } + DBUG_EXECUTE_IF("mts_checkpoint", + { + const char act[]= + "now signal mts_checkpoint_start"; + DBUG_ASSERT(!debug_sync_set_action(rli->info_thd, + STRING_WITH_LEN(act))); + };); #endif /* @@ -5772,14 +5788,23 @@ bool mts_checkpoint_routine(Relay_log_info *rli, ulonglong period, cnt is zero. This value means that the checkpoint information will be completely reset. */ - rli->reset_notified_checkpoint(cnt, rli->gaq->lwm.ts, need_data_lock); - + ts= rli->gaq->empty() + ? 0 + : reinterpret_cast(rli->gaq->head_queue())->ts; + rli->reset_notified_checkpoint(cnt, &ts, need_data_lock); /* end-of "Coordinator::"commit_positions" */ end: #ifndef DBUG_OFF if (DBUG_EVALUATE_IF("check_slave_debug_group", 1, 0)) DBUG_SUICIDE(); + DBUG_EXECUTE_IF("mts_checkpoint", + { + const char act[]= + "now signal mts_checkpoint_end"; + DBUG_ASSERT(!debug_sync_set_action(rli->info_thd, + STRING_WITH_LEN(act))); + };); #endif set_timespec_nsec(rli->last_clock, 0); @@ -7981,9 +8006,6 @@ static Log_event* next_event(Relay_log_info* rli) */ (void) mts_checkpoint_routine(rli, period, false, true/*need_data_lock=true*/); // TODO: ALFRANIO ERROR mysql_mutex_lock(log_lock); - // More to the empty relay-log all assigned events done so reset it. - if (rli->gaq->empty()) - rli->last_master_timestamp= 0; if (DBUG_EVALUATE_IF("check_slave_debug_group", 1, 0)) period= 10000000ULL;