--source include/have_debug.inc

# make the test only run once (STMT is actually needed because we rely
# on SHOW PROCESS LIST output in some of the tests)
--source include/have_binlog_format_statement.inc

# this test logics requires adaption to MTS policies for SBM
# (see rpl_parallel_seconds_behind_master.test)
--source include/not_mts_slave_parallel_workers.inc

--source include/master-slave.inc

call mtr.add_suppression('Unsafe statement binlogged in statement format since BINLOG_FORMAT = STATEMENT');

#
# BUG#29309 test case
# 
# What to test? 
#
# We want to check that issuing FLUSH LOGS on the slave does not cause
# transient, incorrect calculation of Seconds_Behind_Master while SQL
# thread is executing an event.
#
# How to test?
#
# 1. let slave start 3 seconds after an insert on table t1 is issued
#    on the master 
# 2. while locking t1 for write (SQL thread is on-hold) assert that
#    slave is 3 seconds behind the master
# 3. sleep 3 more seconds
# 4. repeat step #2, but before checking Seconds_Behind_Master, issue
#    a FLUSH LOGS.
# 5. assert that Seconds_Behind_Master is within the expected time window

connection master;
create table t1 (f1 int);
--source include/sync_slave_sql_with_master.inc
source include/stop_slave.inc;
connection master;
let $start= `SELECT UNIX_TIMESTAMP()`;
insert into t1 values (1);
let $stop_exec= `SELECT UNIX_TIMESTAMP()`;

real_sleep 3;

connection slave;
lock table t1 write;
source include/start_slave.inc;

# ok, now wait for the SQL thread to start the insert
let $wait_timeout= 60; # Override default of 30 seconds with 60.
let $show_statement= SHOW PROCESSLIST;
let $field= Info;
let $condition= = 'insert into t1 values (1)';
source include/wait_show_condition.inc;

# While the SQL thread executes an event, the following should hold:
# Seconds_Behind_Master = NOW - the event timestamp set by the master
# (for query log events it's event creation time + exec_time).
#
# ASSERTION: check that SBM shows at least 3 seconds

let $sbm= query_get_value("SHOW SLAVE STATUS", Seconds_Behind_Master, 1);
# We need to deduct execution time on master to SBM lower_bound.
# SBM= now - (ev.when + ev.exec_time)
# Also deduct a second to handle rounding differences.
let $lower_bound= `SELECT 3 - ($stop_exec - $start) - 1`;
let $stop= `SELECT UNIX_TIMESTAMP()`;
let $upper_bound= `SELECT $stop - $start`;
let $assert_text= Seconds_Behind_Master must be between 'lower_bound' and 'upper_bound';
let $assert_cond= $lower_bound <= $sbm AND $sbm <= $upper_bound;
source include/assert.inc;

unlock tables;
connection master;
--source include/sync_slave_sql_with_master.inc
lock table t1 write;
connection master;
let $start= `SELECT UNIX_TIMESTAMP()`;
insert into t1 values (2);
let $stop_exec= `SELECT UNIX_TIMESTAMP()`;

real_sleep 3;

connection slave;
# ok, now wait for the SQL thread to start the insert
let $wait_timeout= 60; # Override default of 30 seconds with 60.
let $show_statement= SHOW PROCESSLIST;
let $field= Info;
let $condition= = 'insert into t1 values (2)';
source include/wait_show_condition.inc;

# If FLUSH LOGS is executed while the slave is executing an event, it
# should not affect Seconds_Behind_Master.
#
# ASSERTION: flush logs will not reset the sbm value
flush logs;

real_sleep 3;

let $sbm= query_get_value("SHOW SLAVE STATUS", Seconds_Behind_Master, 1);
# We need to deduct execution time on master to SBM lower_bound.
# SBM= now - (ev.when + ev.exec_time)
# Also deduct a second to handle rounding differences.
let $lower_bound= `SELECT 6 - ($stop_exec - $start) - 1`;
let $stop= `SELECT UNIX_TIMESTAMP()`;
let $upper_bound= `SELECT $stop - $start`;
let $assert_text= Seconds_Behind_Master must be between 'lower_bound' and 'upper_bound';
let $assert_cond= $lower_bound <= $sbm AND $sbm <= $upper_bound;
source include/assert.inc;

unlock tables;
connection master;
drop table t1;
--source include/sync_slave_sql_with_master.inc

#
# BUG#52166 test case 
#
# What to test?
#
# We want to test that Seconds_Behind_Master does not spike when SQL
# thread awakes to process a newly arrived event (queued by IO
# thread). Additionally, we want to assert that while SQL thread is
# waiting Seconds_Behind_Master will show zero.
#
# How to test?
#
#  1. Check that seconds behind master is set to 0 when SQL thread
#     waits for more events. We do this by first waiting for process
#     list to show SQL thread is indeed waiting and then inspect
#     Seconds_Behind_Master value.
#
#  2. Check that seconds behind master is updated once after a newly
#     received event starts to be processed. We do this by putting SQL
#     thread on hold by locking explicitly table t1. We then wait for
#     process list to show that SQL thread started processing the
#     desired query. At that time we inspect the Seconds_Behind_Master
#     and assert that it is in the desired time window.

-- source include/rpl_reset.inc
-- connection master

# this will increase the timestamp +3600, so it becomes
# clear at the slave that it must show 0 and not 3600
--let $debug_point= dec_event_time_by_1_hour
--source include/add_debug_point.inc
CREATE TABLE t1 (a INT);
--source include/sync_slave_sql_with_master.inc

# ok, now wait for the SQL thread to sleep
let $wait_timeout= 60; # Override default of 30 seconds with 60.
let $show_statement= SHOW PROCESSLIST;
let $field= State;
let $condition= = 'Slave has read all relay log; waiting for more updates';
-- source include/wait_show_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;

-- connection slave
LOCK TABLE t1 WRITE;

-- connection master

# Now we will be testing that seconds behind master 
# is set correctly once the event is dequeued and is executing.
# To achieve this goal we will make the event timestamp
# to be shifted 3600 seconds (so that time difference 
# becomes clear). 
#
# 10 seconds, this will give us time at the slave to 
# show that Seconds_Behind_Master will increase when
# this query starts to execute.
#
let $start= `SELECT UNIX_TIMESTAMP()`;
-- disable_warnings
INSERT INTO t1 VALUES (3);
-- enable_warnings
let $stop_exec= `SELECT UNIX_TIMESTAMP()`;

-- connection slave

# ok, now wait for the SQL thread to start the insert
let $wait_timeout= 60; # Override default of 30 seconds with 60.
let $show_statement= SHOW PROCESSLIST;
let $field= Info;
let $condition= = 'INSERT INTO t1 VALUES (3)';
-- source include/wait_show_condition.inc

-- let $sbm= query_get_value("SHOW SLAVE STATUS", Seconds_Behind_Master, 1)
# We need to deduct execution time on master to SBM lower_bound.
# SBM= now - (ev.when + ev.exec_time)
# Also deduct 5 seconds to have a safety margin.
let $lower_bound= `SELECT 3600 - ($stop_exec - $start) - 5`;
let $assert_text= Seconds_Behind_Master must be greater or equal than 'lower_bound';
let $assert_cond= $lower_bound <= $sbm;
source include/assert.inc;

UNLOCK TABLES;

-- connection master
--let $debug_point= dec_event_time_by_1_hour
--source include/remove_debug_point.inc
--source include/sync_slave_sql_with_master.inc


# Check that Seconds_behind_master is greater than or equal to the delay when
# the slave has not yet applied the event

--let $delay= 10
--source include/stop_slave.inc
--eval CHANGE MASTER TO MASTER_DELAY= $delay

--source include/rpl_connection_master.inc
--let $start= `SELECT UNIX_TIMESTAMP()`
INSERT INTO t1 VALUES (47);
--let $stop_exec= `SELECT UNIX_TIMESTAMP()`

--source include/rpl_connection_slave.inc
LOCK TABLE t1 WRITE;
--source include/start_slave.inc

# now wait for the SQL thread to start the insert
# override default wait_timeout of 30 seconds with 60.
--let $wait_timeout= 60
--let $show_statement= SHOW PROCESSLIST
--let $field= Info
--let $condition= = 'INSERT INTO t1 VALUES (47)'
--source include/wait_show_condition.inc

# While the SQL thread executes an event, the following should hold:
# Seconds_Behind_Master = NOW - the event timestamp set by the master
# (for query log events it's event creation time + exec_time).
#
# ASSERTION: check that SBM shows at least the delay

--let $sbm= query_get_value("SHOW SLAVE STATUS", Seconds_Behind_Master, 1)
# We need to deduct execution time on master to SBM lower_bound.
# SBM= now - (ev.when + ev.exec_time)
# Also deduct a second to handle rounding differences.
--let $lower_bound= `SELECT $delay - ($stop_exec - $start) - 1`
--let $stop= `SELECT UNIX_TIMESTAMP()`
# Also add a second to handle rounding differences.
--let $upper_bound= `SELECT $stop - $start +1`
--let $assert_text= Seconds_Behind_Master must be between 'lower_bound' and 'upper_bound'
--let $assert_cond= $lower_bound <= $sbm AND $sbm <= $upper_bound
--source include/assert.inc

UNLOCK TABLES;
--source include/rpl_connection_master.inc
--source include/sync_slave_sql_with_master.inc

# clean up
--source include/stop_slave.inc
CHANGE MASTER TO MASTER_DELAY= 0;
--source include/start_slave.inc
--source include/rpl_connection_master.inc
DROP TABLE t1;
--source include/sync_slave_sql_with_master.inc
--source include/rpl_end.inc