Skip to content

Commit

Permalink
MDEV-7802: group commit status variable addition
Browse files Browse the repository at this point in the history 
Backport into 10.0
  • Loading branch information
@knielsen
knielsen committed Apr 29, 2015
1 parent ed701c6 commit 9088f26
Show file tree
Hide file tree
Showing 5 changed files with 249 additions and 1 deletion.
3 changes: 3 additions & 0 deletions mysql-test/r/features.result
View file
Original file line number Diff line number Diff line change
Expand Up @@ -120,6 +120,9 @@ drop trigger trg;
drop table t1;
show status like "%trigger%";
Variable_name Value
Binlog_group_commit_trigger_count 0
Binlog_group_commit_trigger_lock_wait 0
Binlog_group_commit_trigger_timeout 0
Com_create_trigger 1
Com_drop_trigger 1
Com_show_create_trigger 0
Expand Down
98 changes: 98 additions & 0 deletions mysql-test/suite/binlog/r/binlog_commit_wait.result
View file
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,14 @@ SET @old_count= @@GLOBAL.binlog_commit_wait_count;
SET GLOBAL binlog_commit_wait_count= 3;
SET @old_usec= @@GLOBAL.binlog_commit_wait_usec;
SET GLOBAL binlog_commit_wait_usec= 20000000;
SELECT variable_value INTO @group_commits FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commits';
SELECT variable_value INTO @group_commit_trigger_count FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_count';
SELECT variable_value INTO @group_commit_trigger_timeout FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_timeout';
SELECT variable_value INTO @group_commit_trigger_lock_wait FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_lock_wait';
SET @a= current_timestamp();
BEGIN;
INSERT INTO t1 VALUES (1,0);
Expand All @@ -13,6 +21,22 @@ SET @b= unix_timestamp(current_timestamp()) - unix_timestamp(@a);
SELECT IF(@b < 20, "Ok", CONCAT("Error: too much time elapsed: ", @b, " seconds >= 20"));
IF(@b < 20, "Ok", CONCAT("Error: too much time elapsed: ", @b, " seconds >= 20"))
Ok
SELECT variable_value - @group_commits FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commits';
variable_value - @group_commits
1
SELECT variable_value - @group_commit_trigger_count FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_count';
variable_value - @group_commit_trigger_count
0
SELECT variable_value - @group_commit_trigger_timeout FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_timeout';
variable_value - @group_commit_trigger_timeout
0
SELECT variable_value - @group_commit_trigger_lock_wait FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_lock_wait';
variable_value - @group_commit_trigger_lock_wait
1
ERROR 23000: Duplicate entry '1' for key 'PRIMARY'
SET @a= current_timestamp();
INSERT INTO t1 VALUES (2,0);
Expand All @@ -22,6 +46,22 @@ SET @b= unix_timestamp(current_timestamp()) - unix_timestamp(@a);
SELECT IF(@b < 20, "Ok", CONCAT("Error: too much time elapsed: ", @b, " seconds >= 20"));
IF(@b < 20, "Ok", CONCAT("Error: too much time elapsed: ", @b, " seconds >= 20"))
Ok
SELECT variable_value - @group_commits FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commits';
variable_value - @group_commits
2
SELECT variable_value - @group_commit_trigger_count FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_count';
variable_value - @group_commit_trigger_count
1
SELECT variable_value - @group_commit_trigger_timeout FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_timeout';
variable_value - @group_commit_trigger_timeout
0
SELECT variable_value - @group_commit_trigger_lock_wait FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_lock_wait';
variable_value - @group_commit_trigger_lock_wait
1
SET @a= current_timestamp();
INSERT INTO t1 VALUES (6,0);
BEGIN;
Expand All @@ -36,13 +76,70 @@ SET @b= unix_timestamp(current_timestamp()) - unix_timestamp(@a);
SELECT IF(@b < 20, "Ok", CONCAT("Error: too much time elapsed: ", @b, " seconds >= 20"));
IF(@b < 20, "Ok", CONCAT("Error: too much time elapsed: ", @b, " seconds >= 20"))
Ok
SELECT variable_value - @group_commits FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commits';
variable_value - @group_commits
3
SELECT variable_value - @group_commit_trigger_count FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_count';
variable_value - @group_commit_trigger_count
1
SELECT variable_value - @group_commit_trigger_timeout FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_timeout';
variable_value - @group_commit_trigger_timeout
0
SELECT variable_value - @group_commit_trigger_lock_wait FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_lock_wait';
variable_value - @group_commit_trigger_lock_wait
2
SET @a= current_timestamp();
INSERT INTO t1 VALUES (7,0);
INSERT INTO t1 VALUES (8,0);
SET @b= unix_timestamp(current_timestamp()) - unix_timestamp(@a);
SELECT IF(@b < 20, "Ok", CONCAT("Error: too much time elapsed: ", @b, " seconds >= 20"));
IF(@b < 20, "Ok", CONCAT("Error: too much time elapsed: ", @b, " seconds >= 20"))
Ok
SELECT variable_value - @group_commits FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commits';
variable_value - @group_commits
4
SELECT variable_value - @group_commit_trigger_count FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_count';
variable_value - @group_commit_trigger_count
2
SELECT variable_value - @group_commit_trigger_timeout FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_timeout';
variable_value - @group_commit_trigger_timeout
0
SELECT variable_value - @group_commit_trigger_lock_wait FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_lock_wait';
variable_value - @group_commit_trigger_lock_wait
2
SET @a= current_timestamp();
SET GLOBAL binlog_commit_wait_usec= 5*1000*1000;
INSERT INTO t1 VALUES (9,0);
SET @b= unix_timestamp(current_timestamp()) - unix_timestamp(@a);
SELECT IF(@b < 4, CONCAT("Error: too little time elapsed: ", @b, " seconds < 4"),
IF(@b < 20, "Ok", CONCAT("Error: too much time elapsed: ", @b, " seconds >= 20")));
IF(@b < 4, CONCAT("Error: too little time elapsed: ", @b, " seconds < 4"),
IF(@b < 20, "Ok", CONCAT("Error: too much time elapsed: ", @b, " seconds >= 20")))
Ok
SELECT variable_value - @group_commits FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commits';
variable_value - @group_commits
5
SELECT variable_value - @group_commit_trigger_count FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_count';
variable_value - @group_commit_trigger_count
2
SELECT variable_value - @group_commit_trigger_timeout FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_timeout';
variable_value - @group_commit_trigger_timeout
1
SELECT variable_value - @group_commit_trigger_lock_wait FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_lock_wait';
variable_value - @group_commit_trigger_lock_wait
2
SELECT * FROM t1 ORDER BY a;
a b
1 11
Expand All @@ -52,6 +149,7 @@ a b
6 0
7 0
8 0
9 0
DROP TABLE t1;
SET GLOBAL binlog_commit_wait_count= @old_count;
SET GLOBAL binlog_commit_wait_usec= @old_usec;
106 changes: 106 additions & 0 deletions mysql-test/suite/binlog/t/binlog_commit_wait.test
View file
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,20 @@ connect(con1,localhost,root,,test);
connect(con2,localhost,root,,test);
connect(con3,localhost,root,,test);

# Get Initial status measurements
--connection default
SELECT variable_value INTO @group_commits FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commits';
SELECT variable_value INTO @group_commit_trigger_count FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_count';
SELECT variable_value INTO @group_commit_trigger_timeout FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_timeout';
SELECT variable_value INTO @group_commit_trigger_lock_wait FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_lock_wait';

# Note: binlog_group_commits is counted at the start of the group and group_commit_trigger_* is
# counted near when the groups its finalised.

# Check that if T2 goes to wait for a row lock of T1 while T1 is waiting for
# more transactions to arrive for group commit, the commit of T1 will complete
# immediately.
Expand All @@ -37,6 +51,23 @@ reap;
SET @b= unix_timestamp(current_timestamp()) - unix_timestamp(@a);
SELECT IF(@b < 20, "Ok", CONCAT("Error: too much time elapsed: ", @b, " seconds >= 20"));

# All connections are to the same server. One transaction occurs on con1. It is
# commited before con2 is started. con2 transaction violates the unique key contraint. This
# type of group commit is binlog_group_commit_trigger_lock_wait so that further con2
# transactions will occur afterwards as they may be as result of the ER_DUP_ENTRY on the
# application side.
# before: binlog_group_commit=0, binlog_group_commit_trigger_count=0
# before: binlog_group_commit_trigger_timeout=0, binlog_group_commit_trigger_lock_wait=0
# after: binlog_group_commit+1 by reason of binlog_group_commit_trigger_lock_wait+1
SELECT variable_value - @group_commits FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commits';
SELECT variable_value - @group_commit_trigger_count FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_count';
SELECT variable_value - @group_commit_trigger_timeout FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_timeout';
SELECT variable_value - @group_commit_trigger_lock_wait FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_lock_wait';

--connection con2
--error ER_DUP_ENTRY
reap;
Expand Down Expand Up @@ -64,6 +95,21 @@ reap;
SET @b= unix_timestamp(current_timestamp()) - unix_timestamp(@a);
SELECT IF(@b < 20, "Ok", CONCAT("Error: too much time elapsed: ", @b, " seconds >= 20"));

# All connections are to the same server. 3 non-conflicting transaction occur
# on each connection. The binlog_commit_wait_count=3 at the start therefore 1
# group is committed by virtue of reaching 3 transactions. Hence
# binlog_group_commit_trigger_count is incremented.
# before: binlog_group_commit=1, binlog_group_commit_trigger_count=0
# before: binlog_group_commit_trigger_timeout=0, binlog_group_commit_trigger_lock_wait=1
# after: binlog_group_commit+1 by reason of binlog_group_commit_trigger_count+1
SELECT variable_value - @group_commits FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commits';
SELECT variable_value - @group_commit_trigger_count FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_count';
SELECT variable_value - @group_commit_trigger_timeout FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_timeout';
SELECT variable_value - @group_commit_trigger_lock_wait FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_lock_wait';

# Test that commit triggers immediately if there is already a transaction
# waiting on another transaction that reaches its commit.
Expand Down Expand Up @@ -99,6 +145,21 @@ reap;
SET @b= unix_timestamp(current_timestamp()) - unix_timestamp(@a);
SELECT IF(@b < 20, "Ok", CONCAT("Error: too much time elapsed: ", @b, " seconds >= 20"));

# All connections are to the same server. con2 and con3 updates are aquiring
# the same row lock for a=1. Either con2 or con3 will be in a lock wait
# thefore the binlog_group_commit_trigger_lock_wait is incremented.
# before: binlog_group_commit=2, binlog_group_commit_trigger_count=1
# before: binlog_group_commit_trigger_timeout=0, binlog_group_commit_trigger_lock_wait=1
# after: binlog_group_commit+1 by reason of binlog_group_commit_trigger_lock_wait+1
SELECT variable_value - @group_commits FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commits';
SELECT variable_value - @group_commit_trigger_count FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_count';
SELECT variable_value - @group_commit_trigger_timeout FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_timeout';
SELECT variable_value - @group_commit_trigger_lock_wait FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_lock_wait';

--connection default
SET @a= current_timestamp();

Expand All @@ -114,6 +175,51 @@ reap;
SET @b= unix_timestamp(current_timestamp()) - unix_timestamp(@a);
SELECT IF(@b < 20, "Ok", CONCAT("Error: too much time elapsed: ", @b, " seconds >= 20"));

# The con1 and con2 transactions above are combined with the 'send UPDATE t1 SET b=b+10 WHERE a=1;'
# on con3 from the previous block. So we have 3 so this is a count based group.
# before: binlog_group_commit=3, binlog_group_commit_trigger_count=1
# before: binlog_group_commit_trigger_timeout=0, binlog_group_commit_trigger_lock_wait=2
# after: binlog_group_commit+1 by reason of binlog_group_commit_trigger_count+1
SELECT variable_value - @group_commits FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commits';
SELECT variable_value - @group_commit_trigger_count FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_count';
SELECT variable_value - @group_commit_trigger_timeout FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_timeout';
SELECT variable_value - @group_commit_trigger_lock_wait FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_lock_wait';

# Test that when the binlog_commit_wait_usec is reached the tranction gets a group commit

--connection default
SET @a= current_timestamp();
SET GLOBAL binlog_commit_wait_usec= 5*1000*1000;

--connection con1
reap;
INSERT INTO t1 VALUES (9,0);

--connection default
SET @b= unix_timestamp(current_timestamp()) - unix_timestamp(@a);
SELECT IF(@b < 4, CONCAT("Error: too little time elapsed: ", @b, " seconds < 4"),
IF(@b < 20, "Ok", CONCAT("Error: too much time elapsed: ", @b, " seconds >= 20")));

# con1 pushes 1 transaction. The count was for 3 to occur before a group commit.
# The timeout is 5 seconds but we allow between 4 and 20 because of the fragile nature
# of time in test. This is a timeout causing the commit so binlog_group_commit_trigger_timeout
# is incremented.
# before: binlog_group_commit=4, binlog_group_commit_trigger_count=2
# before: binlog_group_commit_trigger_timeout=0, binlog_group_commit_trigger_lock_wait=2
# after: binlog_group_commit+1 by reason of binlog_group_commit_trigger_timeout+1
SELECT variable_value - @group_commits FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commits';
SELECT variable_value - @group_commit_trigger_count FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_count';
SELECT variable_value - @group_commit_trigger_timeout FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_timeout';
SELECT variable_value - @group_commit_trigger_lock_wait FROM information_schema.global_status
WHERE variable_name = 'binlog_group_commit_trigger_lock_wait';

--connection default
SELECT * FROM t1 ORDER BY a;

Expand Down
40 changes: 39 additions & 1 deletion sql/log.cc
View file
Original file line number Diff line number Diff line change
Expand Up @@ -95,6 +95,9 @@ mysql_mutex_t LOCK_commit_ordered;

static ulonglong binlog_status_var_num_commits;
static ulonglong binlog_status_var_num_group_commits;
static ulonglong binlog_status_group_commit_trigger_count;
static ulonglong binlog_status_group_commit_trigger_lock_wait;
static ulonglong binlog_status_group_commit_trigger_timeout;
static char binlog_snapshot_file[FN_REFLEN];
static ulonglong binlog_snapshot_position;

Expand All @@ -104,6 +107,12 @@ static SHOW_VAR binlog_status_vars_detail[]=
(char *)&binlog_status_var_num_commits, SHOW_LONGLONG},
{"group_commits",
(char *)&binlog_status_var_num_group_commits, SHOW_LONGLONG},
{"group_commit_trigger_count",
(char *)&binlog_status_group_commit_trigger_count, SHOW_LONGLONG},
{"group_commit_trigger_lock_wait",
(char *)&binlog_status_group_commit_trigger_lock_wait, SHOW_LONGLONG},
{"group_commit_trigger_timeout",
(char *)&binlog_status_group_commit_trigger_timeout, SHOW_LONGLONG},
{"snapshot_file",
(char *)&binlog_snapshot_file, SHOW_CHAR},
{"snapshot_position",
Expand Down Expand Up @@ -3035,6 +3044,8 @@ MYSQL_BIN_LOG::MYSQL_BIN_LOG(uint *sync_period)
bytes_written(0), file_id(1), open_count(1),
group_commit_queue(0), group_commit_queue_busy(FALSE),
num_commits(0), num_group_commits(0),
group_commit_trigger_count(0), group_commit_trigger_timeout(0),
group_commit_trigger_lock_wait(0),
sync_period_ptr(sync_period), sync_counter(0),
state_file_deleted(false), binlog_state_recover_done(false),
is_relay_log(0), signal_cnt(0),
Expand Down Expand Up @@ -7562,8 +7573,18 @@ MYSQL_BIN_LOG::wait_for_sufficient_commits()
mysql_mutex_assert_owner(&LOCK_prepare_ordered);

for (e= last_head= group_commit_queue, count= 0; e; e= e->next)
if (++count >= opt_binlog_commit_wait_count || unlikely(e->thd->has_waiter))
{
if (++count >= opt_binlog_commit_wait_count)
{
group_commit_trigger_count++;
return;
}
if (unlikely(e->thd->has_waiter))
{
group_commit_trigger_lock_wait++;
return;
}
}

mysql_mutex_unlock(&LOCK_log);
set_timespec_nsec(wait_until, (ulonglong)1000*opt_binlog_commit_wait_usec);
Expand All @@ -7576,18 +7597,30 @@ MYSQL_BIN_LOG::wait_for_sufficient_commits()
err= mysql_cond_timedwait(&COND_prepare_ordered, &LOCK_prepare_ordered,
&wait_until);
if (err == ETIMEDOUT)
{
group_commit_trigger_timeout++;
break;
}
if (unlikely(last_head->thd->has_waiter))
{
group_commit_trigger_lock_wait++;
break;
}
head= group_commit_queue;
for (e= head; e && e != last_head; e= e->next)
{
++count;
if (unlikely(e->thd->has_waiter))
{
group_commit_trigger_lock_wait++;
goto after_loop;
}
}
if (count >= opt_binlog_commit_wait_count)
{
group_commit_trigger_count++;
break;
}
last_head= head;
}
after_loop:
Expand Down Expand Up @@ -9771,6 +9804,11 @@ TC_LOG_BINLOG::set_status_variables(THD *thd)
binlog_snapshot_position= last_commit_pos_offset;
}
mysql_mutex_unlock(&LOCK_commit_ordered);
mysql_mutex_lock(&LOCK_prepare_ordered);
binlog_status_group_commit_trigger_count= this->group_commit_trigger_count;
binlog_status_group_commit_trigger_timeout= this->group_commit_trigger_timeout;
binlog_status_group_commit_trigger_lock_wait= this->group_commit_trigger_lock_wait;
mysql_mutex_unlock(&LOCK_prepare_ordered);

if (have_snapshot)
{
Expand Down
3 changes: 3 additions & 0 deletions sql/log.h
View file
Original file line number Diff line number Diff line change
Expand Up @@ -515,6 +515,9 @@ class MYSQL_BIN_LOG: public TC_LOG, private MYSQL_LOG
ulonglong num_commits;
/* Number of group commits done. */
ulonglong num_group_commits;
/* The reason why the group commit was grouped */
ulonglong group_commit_trigger_count, group_commit_trigger_timeout;
ulonglong group_commit_trigger_lock_wait;

/* pointer to the sync period variable, for binlog this will be
sync_binlog_period, for relay log this will be
Expand Down

0 comments on commit 9088f26

Please sign in to comment.