BUG#56343 binlog_cache_use status is bigger than expected

The binlog_cache_use is incremented twice when changes to a transactional table
are committed, i.e. TC_LOG_BINLOG::log_xid calls is called. The problem happens
because log_xid calls both binlog_flush_stmt_cache and binlog_flush_trx_cache
without checking if such caches are empty thus unintentionally increasing the
binlog_cache_use value twice.

Although not explicitly mentioned in the bug, the binlog_cache_disk_use presents
the same problem.

The binlog_cache_use and binlog_cache_disk_use are status variables that are
incremented when transactional (i.e. trx-cache) or non-transactional (i.e.
stmt-cache) changes are committed. They are used to compute the ratio between
the use of disk and memory while gathering updates for a transaction.

The problem reported is fixed by avoiding incrementing the binlog_cache_use
and binlog_cache_disk_use if a cache is empty. We also have decided to increment
both variables when a cache is truncated as the cache is used although its
content is discarded and is not written to the binary log.

In this patch, we take the opportunity to re-organize the code around the
function binlog_flush_trx_cache and binlog_flush_stmt_cache.

mysql-test/extra/binlog_tests/binlog_cache_stat.test:
  Updated the test case with comments and additional tests to check both
  transactional and non-transactional changes and what happens when a 
  is transaction either committed or aborted.
mysql-test/suite/binlog/r/binlog_innodb.result:
  Updated the result file.
mysql-test/suite/binlog/r/binlog_mixed_cache_stat.result:
  Updated the result file.
mysql-test/suite/binlog/r/binlog_row_cache_stat.result:
  Updated the result file.
mysql-test/suite/binlog/r/binlog_stm_cache_stat.result:
  Updated the result file.
mysql-test/suite/binlog/t/binlog_mixed_cache_stat.test:
  Updated the test case with a new source file.
mysql-test/suite/binlog/t/binlog_row_cache_stat.test:
  Updated the test case with a new source file.
mysql-test/suite/binlog/t/binlog_stm_cache_stat.test:
  Updated the test case with a new source file.
sql/log.cc:
  There are four changes in here:
  
    . Computed statistics on binlog_cache_use and binlog_cache_disk_use while
    resting the cache.
  
    . Refactored the code so binlog_flush_cache handles both the trx-cache and
    stmt-cache.
  
    . There are functions that encapsulate the calls to binlog_flush_cache and
    make easier to read the code.
  
    . binlog_commit_flush_stmt_cache is now taking into account the result:
    success or error.
sql/log_event.h:
  Guaranteed Xid_log_event is always classified as a transactional event.

mysql-test/extra/binlog_tests/binlog_cache_stat.test

+# Embedded server doesn't support binlog
+-- source include/not_embedded.inc
+-- source include/have_innodb.inc
+
+# Creating tables
+--disable_warnings
+drop table if exists t1, t2;
+--enable_warnings
+
+create table t1 (a int) engine=innodb;
+create table t2 (a int) engine=myisam;
+
+#
+# This test checks binlog_cache_use and binlog_cache_disk_use when
+# transactions are committed and after when they are aborted.
+#
+
+#
+# Checking commit.
+#
+--echo **** Preparing the enviroment to check commit and its effect on
+--echo **** the binlog_cache_use and binlog_cache_disk_use.
+--echo **** Expected: binlog_cache_use = 0, binlog_cache_disk_use = 0.
+flush status;
+let $exp_cache= 0;
+let $got_cache= query_get_value(show status like "binlog_cache_use", Value, 1);
+let $exp_disk= 0;
+let $got_disk= query_get_value(show status like "binlog_cache_disk_use", Value, 1);
+if (`SELECT $got_cache <> $exp_cache || $got_disk <> $exp_disk`)
+{
+  -- echo "Expected: binlog_cache_use = $exp_cache, binlog_cache_disk_use = $exp_disk but got binlog_cache_use = $got_cache, binlog_cache_disk_use = $got_disk but"
+  -- die
+}
+
+--echo **** Now we are going to create transactional changes which are long enough so
+--echo **** they will be flushed to disk...
+--echo **** Expected: binlog_cache_use = 1, binlog_cache_disk_use = 1.
+let $1=2000;
+disable_query_log;
+begin;
+while ($1)
+{
+ eval insert into t1 values( $1 );
+ dec $1;
+}
+commit;
+enable_query_log;
+let $exp_cache= 1;
+let $got_cache= query_get_value(show status like "binlog_cache_use", Value, 1);
+let $exp_disk= 1;
+let $got_disk= query_get_value(show status like "binlog_cache_disk_use", Value, 1);
+if (`SELECT $got_cache <> $exp_cache || $got_disk <> $exp_disk`)
+{
+  -- echo "Expected: binlog_cache_use = $exp_cache, binlog_cache_disk_use = $exp_disk but got binlog_cache_use = $got_cache, binlog_cache_disk_use = $got_disk but"
+  -- die
+}
+
+--echo **** Transactional changes which should not be flushed to disk and so should not
+--echo **** increase binlog_cache_disk_use.
+--echo **** Expected: binlog_cache_use = 2, binlog_cache_disk_use = 1.
+begin;
+insert into t1 values( 1 );
+commit;
+let $exp_cache= 2;
+let $got_cache= query_get_value(show status like "binlog_cache_use", Value, 1);
+let $exp_disk= 1;
+let $got_disk= query_get_value(show status like "binlog_cache_disk_use", Value, 1);
+if (`SELECT $got_cache <> $exp_cache || $got_disk <> $exp_disk`)
+{
+  -- echo "Expected: binlog_cache_use = $exp_cache, binlog_cache_disk_use = $exp_disk but got binlog_cache_use = $got_cache, binlog_cache_disk_use = $got_disk but"
+  -- die
+}
+
+--echo **** Non-Transactional changes which should not be flushed to disk and so should not
+--echo **** increase binlog_cache_disk_use.
+--echo **** Expected: binlog_cache_use = 3, binlog_cache_disk_use = 1.
+begin;
+insert into t2 values( 1 );
+commit;
+let $exp_cache= 3;
+let $got_cache= query_get_value(show status like "binlog_cache_use", Value, 1);
+let $exp_disk= 1;
+let $got_disk= query_get_value(show status like "binlog_cache_disk_use", Value, 1);
+if (`SELECT $got_cache <> $exp_cache || $got_disk <> $exp_disk`)
+{
+  -- echo "Expected: binlog_cache_use = $exp_cache, binlog_cache_disk_use = $exp_disk but got binlog_cache_use = $got_cache, binlog_cache_disk_use = $got_disk but"
+  -- die
+}
+
+--echo **** Mixed changes which should not be flushed to disk and so should not
+--echo **** increase binlog_cache_disk_use.
+--echo **** Expected: binlog_cache_use = 5, binlog_cache_disk_use = 1.
+begin;
+insert into t1 values( 1 );
+insert into t2 values( 1 );
+commit;
+let $exp_cache= 5;
+let $got_cache= query_get_value(show status like "binlog_cache_use", Value, 1);
+let $exp_disk= 1;
+let $got_disk= query_get_value(show status like "binlog_cache_disk_use", Value, 1);
+if (`SELECT $got_cache <> $exp_cache || $got_disk <> $exp_disk`)
+{
+  -- echo "Expected: binlog_cache_use = $exp_cache, binlog_cache_disk_use = $exp_disk but got binlog_cache_use = $got_cache, binlog_cache_disk_use = $got_disk but"
+  -- die
+}
+
+#
+# Checking abort.
+#
+--echo **** Preparing the enviroment to check abort and its effect on
+--echo **** the binlog_cache_use and binlog_cache_disk_use
+--echo **** Expected: binlog_cache_use = 0, binlog_cache_disk_use = 0.
+flush status;
+let $exp_cache= 0;
+let $got_cache= query_get_value(show status like "binlog_cache_use", Value, 1);
+let $exp_disk= 0;
+let $got_disk= query_get_value(show status like "binlog_cache_disk_use", Value, 1);
+if (`SELECT $got_cache <> $exp_cache || $got_disk <> $exp_disk`)
+{
+  -- echo "Expected: binlog_cache_use = $exp_cache, binlog_cache_disk_use = $exp_disk but got binlog_cache_use = $got_cache, binlog_cache_disk_use = $got_disk but"
+  -- die
+}
+
+--echo **** Now we are going to create transactional changes which are long enough so
+--echo **** they will be flushed to disk...
+--echo **** Expected: binlog_cache_use = 1, binlog_cache_disk_use = 1.
+let $1=2000;
+disable_query_log;
+begin;
+while ($1)
+{
+ eval insert into t1 values( $1 );
+ dec $1;
+}
+rollback;
+enable_query_log;
+let $exp_cache= 1;
+let $got_cache= query_get_value(show status like "binlog_cache_use", Value, 1);
+let $exp_disk= 1;
+let $got_disk= query_get_value(show status like "binlog_cache_disk_use", Value, 1);
+if (`SELECT $got_cache <> $exp_cache || $got_disk <> $exp_disk`)
+{
+  -- echo "Expected: binlog_cache_use = $exp_cache, binlog_cache_disk_use = $exp_disk but got binlog_cache_use = $got_cache, binlog_cache_disk_use = $got_disk but"
+  -- die
+}
+
+--echo **** Transactional changes which should not be flushed to disk and so should not
+--echo **** increase binlog_cache_disk_use.
+--echo **** Expected: binlog_cache_use = 2, binlog_cache_disk_use = 1.
+begin;
+insert into t1 values( 1 );
+rollback;
+let $exp_cache= 2;
+let $got_cache= query_get_value(show status like "binlog_cache_use", Value, 1);
+let $exp_disk= 1;
+let $got_disk= query_get_value(show status like "binlog_cache_disk_use", Value, 1);
+if (`SELECT $got_cache <> $exp_cache || $got_disk <> $exp_disk`)
+{
+  -- echo "Expected: binlog_cache_use = $exp_cache, binlog_cache_disk_use = $exp_disk but got binlog_cache_use = $got_cache, binlog_cache_disk_use = $got_disk but"
+  -- die
+}
+
+--echo **** Non-Transactional changes which should not be flushed to disk and so should not
+--echo **** increase binlog_cache_disk_use.
+--echo **** Expected: binlog_cache_use = 3, binlog_cache_disk_use = 1.
+begin;
+insert into t2 values( 1 );
+rollback;
+let $exp_cache= 3;
+let $got_cache= query_get_value(show status like "binlog_cache_use", Value, 1);
+let $exp_disk= 1;
+let $got_disk= query_get_value(show status like "binlog_cache_disk_use", Value, 1);
+if (`SELECT $got_cache <> $exp_cache || $got_disk <> $exp_disk`)
+{
+  -- echo "Expected: binlog_cache_use = $exp_cache, binlog_cache_disk_use = $exp_disk but got binlog_cache_use = $got_cache, binlog_cache_disk_use = $got_disk but"
+  -- die
+}
+
+--echo **** Mixed changes which should not be flushed to disk and so should not
+--echo **** increase binlog_cache_disk_use.
+--echo **** Expected: binlog_cache_use = 5, binlog_cache_disk_use = 1.
+begin;
+insert into t1 values( 1 );
+insert into t2 values( 1 );
+rollback;
+let $exp_cache= 5;
+let $got_cache= query_get_value(show status like "binlog_cache_use", Value, 1);
+let $exp_disk= 1;
+let $got_disk= query_get_value(show status like "binlog_cache_disk_use", Value, 1);
+if (`SELECT $got_cache <> $exp_cache || $got_disk <> $exp_disk`)
+{
+  -- echo "Expected: binlog_cache_use = $exp_cache, binlog_cache_disk_use = $exp_disk but got binlog_cache_use = $got_cache, binlog_cache_disk_use = $got_disk but"
+  -- die
+}
+drop table t1, t2;

mysql-test/extra/binlog_tests/innodb_stat.test

-# Embedded server doesn't support binlog
--- source include/not_embedded.inc
--- source include/have_innodb.inc
-
-#
-# Let us test binlog_cache_use and binlog_cache_disk_use status vars.
-# Actually this test has nothing to do with innodb per se, it just requires
-# transactional table. 
-#
-flush status;
-show status like "binlog_cache_use";
-show status like "binlog_cache_disk_use";
---disable_warnings
-drop table if exists t1;
---enable_warnings
-
-create table t1 (a int) engine=innodb;
-
-# Now we are going to create transaction which is long enough so its 
-# transaction binlog will be flushed to disk...
-let $1=2000;
-disable_query_log;
-begin;
-while ($1)
-{
- eval insert into t1 values( $1 );
- dec $1;
-}
-commit;
-enable_query_log;
-show status like "binlog_cache_use";
-show status like "binlog_cache_disk_use";
-
-# Transaction which should not be flushed to disk and so should not
-# increase binlog_cache_disk_use.
-begin;
-delete from t1;
-commit;
-show status like "binlog_cache_use";
-show status like "binlog_cache_disk_use";
-drop table t1;

mysql-test/suite/binlog/r/binlog_innodb.result

@@ -123,7 +123,7 @@ Binlog_cache_disk_use	0
 create table t1 (a int) engine=innodb;
 show status like "binlog_cache_use";
 Variable_name	Value
-Binlog_cache_use	2
+Binlog_cache_use	1
 show status like "binlog_cache_disk_use";
 Variable_name	Value
 Binlog_cache_disk_use	1
@@ -132,7 +132,7 @@ delete from t1;
 commit;
 show status like "binlog_cache_use";
 Variable_name	Value
-Binlog_cache_use	4
+Binlog_cache_use	2
 show status like "binlog_cache_disk_use";
 Variable_name	Value
 Binlog_cache_disk_use	1

mysql-test/suite/binlog/r/binlog_mix_innodb_stat.result

-flush status;
-show status like "binlog_cache_use";
-Variable_name	Value
-Binlog_cache_use	0
-show status like "binlog_cache_disk_use";
-Variable_name	Value
-Binlog_cache_disk_use	0
-drop table if exists t1;
-create table t1 (a int) engine=innodb;
-show status like "binlog_cache_use";
-Variable_name	Value
-Binlog_cache_use	2
-show status like "binlog_cache_disk_use";
-Variable_name	Value
-Binlog_cache_disk_use	1
-begin;
-delete from t1;
-commit;
-show status like "binlog_cache_use";
-Variable_name	Value
-Binlog_cache_use	4
-show status like "binlog_cache_disk_use";
-Variable_name	Value
-Binlog_cache_disk_use	1
-drop table t1;

mysql-test/suite/binlog/r/binlog_mixed_cache_stat.result

+drop table if exists t1, t2;
+create table t1 (a int) engine=innodb;
+create table t2 (a int) engine=myisam;
+**** Preparing the enviroment to check commit and its effect on
+**** the binlog_cache_use and binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 0, binlog_cache_disk_use = 0.
+flush status;
+**** Now we are going to create transactional changes which are long enough so
+**** they will be flushed to disk...
+**** Expected: binlog_cache_use = 1, binlog_cache_disk_use = 1.
+**** Transactional changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 2, binlog_cache_disk_use = 1.
+begin;
+insert into t1 values( 1 );
+commit;
+**** Non-Transactional changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 3, binlog_cache_disk_use = 1.
+begin;
+insert into t2 values( 1 );
+commit;
+**** Mixed changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 5, binlog_cache_disk_use = 1.
+begin;
+insert into t1 values( 1 );
+insert into t2 values( 1 );
+commit;
+**** Preparing the enviroment to check abort and its effect on
+**** the binlog_cache_use and binlog_cache_disk_use
+**** Expected: binlog_cache_use = 0, binlog_cache_disk_use = 0.
+flush status;
+**** Now we are going to create transactional changes which are long enough so
+**** they will be flushed to disk...
+**** Expected: binlog_cache_use = 1, binlog_cache_disk_use = 1.
+**** Transactional changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 2, binlog_cache_disk_use = 1.
+begin;
+insert into t1 values( 1 );
+rollback;
+**** Non-Transactional changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 3, binlog_cache_disk_use = 1.
+begin;
+insert into t2 values( 1 );
+rollback;
+Warnings:
+Warning	1196	Some non-transactional changed tables couldn't be rolled back
+**** Mixed changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 5, binlog_cache_disk_use = 1.
+begin;
+insert into t1 values( 1 );
+insert into t2 values( 1 );
+rollback;
+Warnings:
+Warning	1196	Some non-transactional changed tables couldn't be rolled back
+drop table t1, t2;

mysql-test/suite/binlog/r/binlog_row_cache_stat.result

+drop table if exists t1, t2;
+create table t1 (a int) engine=innodb;
+create table t2 (a int) engine=myisam;
+**** Preparing the enviroment to check commit and its effect on
+**** the binlog_cache_use and binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 0, binlog_cache_disk_use = 0.
+flush status;
+**** Now we are going to create transactional changes which are long enough so
+**** they will be flushed to disk...
+**** Expected: binlog_cache_use = 1, binlog_cache_disk_use = 1.
+**** Transactional changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 2, binlog_cache_disk_use = 1.
+begin;
+insert into t1 values( 1 );
+commit;
+**** Non-Transactional changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 3, binlog_cache_disk_use = 1.
+begin;
+insert into t2 values( 1 );
+commit;
+**** Mixed changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 5, binlog_cache_disk_use = 1.
+begin;
+insert into t1 values( 1 );
+insert into t2 values( 1 );
+commit;
+**** Preparing the enviroment to check abort and its effect on
+**** the binlog_cache_use and binlog_cache_disk_use
+**** Expected: binlog_cache_use = 0, binlog_cache_disk_use = 0.
+flush status;
+**** Now we are going to create transactional changes which are long enough so
+**** they will be flushed to disk...
+**** Expected: binlog_cache_use = 1, binlog_cache_disk_use = 1.
+**** Transactional changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 2, binlog_cache_disk_use = 1.
+begin;
+insert into t1 values( 1 );
+rollback;
+**** Non-Transactional changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 3, binlog_cache_disk_use = 1.
+begin;
+insert into t2 values( 1 );
+rollback;
+Warnings:
+Warning	1196	Some non-transactional changed tables couldn't be rolled back
+**** Mixed changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 5, binlog_cache_disk_use = 1.
+begin;
+insert into t1 values( 1 );
+insert into t2 values( 1 );
+rollback;
+Warnings:
+Warning	1196	Some non-transactional changed tables couldn't be rolled back
+drop table t1, t2;

mysql-test/suite/binlog/r/binlog_row_innodb_stat.result

-flush status;
-show status like "binlog_cache_use";
-Variable_name	Value
-Binlog_cache_use	0
-show status like "binlog_cache_disk_use";
-Variable_name	Value
-Binlog_cache_disk_use	0
-drop table if exists t1;
-create table t1 (a int) engine=innodb;
-show status like "binlog_cache_use";
-Variable_name	Value
-Binlog_cache_use	2
-show status like "binlog_cache_disk_use";
-Variable_name	Value
-Binlog_cache_disk_use	1
-begin;
-delete from t1;
-commit;
-show status like "binlog_cache_use";
-Variable_name	Value
-Binlog_cache_use	4
-show status like "binlog_cache_disk_use";
-Variable_name	Value
-Binlog_cache_disk_use	1
-drop table t1;

mysql-test/suite/binlog/r/binlog_stm_cache_stat.result

+drop table if exists t1, t2;
+create table t1 (a int) engine=innodb;
+create table t2 (a int) engine=myisam;
+**** Preparing the enviroment to check commit and its effect on
+**** the binlog_cache_use and binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 0, binlog_cache_disk_use = 0.
+flush status;
+**** Now we are going to create transactional changes which are long enough so
+**** they will be flushed to disk...
+**** Expected: binlog_cache_use = 1, binlog_cache_disk_use = 1.
+**** Transactional changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 2, binlog_cache_disk_use = 1.
+begin;
+insert into t1 values( 1 );
+commit;
+**** Non-Transactional changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 3, binlog_cache_disk_use = 1.
+begin;
+insert into t2 values( 1 );
+commit;
+**** Mixed changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 5, binlog_cache_disk_use = 1.
+begin;
+insert into t1 values( 1 );
+insert into t2 values( 1 );
+commit;
+**** Preparing the enviroment to check abort and its effect on
+**** the binlog_cache_use and binlog_cache_disk_use
+**** Expected: binlog_cache_use = 0, binlog_cache_disk_use = 0.
+flush status;
+**** Now we are going to create transactional changes which are long enough so
+**** they will be flushed to disk...
+**** Expected: binlog_cache_use = 1, binlog_cache_disk_use = 1.
+**** Transactional changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 2, binlog_cache_disk_use = 1.
+begin;
+insert into t1 values( 1 );
+rollback;
+**** Non-Transactional changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 3, binlog_cache_disk_use = 1.
+begin;
+insert into t2 values( 1 );
+rollback;
+Warnings:
+Warning	1196	Some non-transactional changed tables couldn't be rolled back
+**** Mixed changes which should not be flushed to disk and so should not
+**** increase binlog_cache_disk_use.
+**** Expected: binlog_cache_use = 5, binlog_cache_disk_use = 1.
+begin;
+insert into t1 values( 1 );
+insert into t2 values( 1 );
+rollback;
+Warnings:
+Warning	1196	Some non-transactional changed tables couldn't be rolled back
+drop table t1, t2;

mysql-test/suite/binlog/r/binlog_stm_innodb_stat.result

-flush status;
-show status like "binlog_cache_use";
-Variable_name	Value
-Binlog_cache_use	0
-show status like "binlog_cache_disk_use";
-Variable_name	Value
-Binlog_cache_disk_use	0
-drop table if exists t1;
-create table t1 (a int) engine=innodb;
-show status like "binlog_cache_use";
-Variable_name	Value
-Binlog_cache_use	2
-show status like "binlog_cache_disk_use";
-Variable_name	Value
-Binlog_cache_disk_use	1
-begin;
-delete from t1;
-commit;
-show status like "binlog_cache_use";
-Variable_name	Value
-Binlog_cache_use	4
-show status like "binlog_cache_disk_use";
-Variable_name	Value
-Binlog_cache_disk_use	1
-drop table t1;

mysql-test/suite/binlog/t/binlog_mix_innodb_stat.test → mysql-test/suite/binlog/t/binlog_mixed_cache_stat.test

@@ -2,4 +2,4 @@
 # For both statement and row based bin logs 9/19/2005 [jbm]
 
 -- source include/have_binlog_format_mixed.inc
--- source extra/binlog_tests/innodb_stat.test
+-- source extra/binlog_tests/binlog_cache_stat.test

mysql-test/suite/binlog/t/binlog_row_innodb_stat.test → mysql-test/suite/binlog/t/binlog_row_cache_stat.test

@@ -2,4 +2,4 @@
 # For both statement and row based bin logs 9/19/2005 [jbm]
 
 -- source include/have_binlog_format_row.inc
--- source extra/binlog_tests/innodb_stat.test
+-- source extra/binlog_tests/binlog_cache_stat.test

mysql-test/suite/binlog/t/binlog_stm_innodb_stat.test → mysql-test/suite/binlog/t/binlog_stm_cache_stat.test

@@ -2,4 +2,4 @@
 # For both statement and row based bin logs 9/19/2005 [jbm]
 
 -- source include/have_binlog_format_statement.inc
--- source extra/binlog_tests/innodb_stat.test
+-- source extra/binlog_tests/binlog_cache_stat.test

sql/log.cc

@@ -257,11 +257,20 @@ public:
 
   void reset()
   {
+    compute_statistics();
     truncate(0);
     changes_to_non_trans_temp_table_flag= FALSE;
     incident= FALSE;
     before_stmt_pos= MY_OFF_T_UNDEF;
     cache_log.end_of_file= max_binlog_cache_size;
+    /*
+      The truncate function calls reinit_io_cache that calls my_b_flush_io_cache
+      which may increase disk_write. This breaks the "disk_writes"' use by the
+      binary log which aims to compute the ratio between in-memory cache usage
+      and disk cache usage. To avoid this undesirable behavior, we reset the
+      variable after truncating the cache.
+    */
+    cache_log.disk_writes= 0;
     DBUG_ASSERT(empty());
   }
 
@@ -321,6 +330,22 @@ private:
   */
   bool changes_to_non_trans_temp_table_flag;
 
+  /**
+    This function computes binlog cache and disk usage.
+
+    @param cache_data  Pointer to the cache where data is
+                       stored.
+  */
+  void compute_statistics()
+  {
+    if (!empty())
+    {
+      statistic_increment(binlog_cache_use, &LOCK_status);
+      if (cache_log.disk_writes != 0)
+        statistic_increment(binlog_cache_disk_use, &LOCK_status);
+    }
+  }
+
   /*
     It truncates the cache to a certain position. This includes deleting the
     pending event.
@@ -1506,56 +1531,121 @@ static int binlog_close_connection(handlerton *hton, THD *thd)
 }
 
 /**
-  This function flushes a transactional cache upon commit/rollback.
+  This function flushes a cache upon commit/rollback.
 
-  @param thd        The thread whose transaction should be flushed
-  @param cache_mngr Pointer to the cache data to be flushed
-  @param end_ev     The end event either commit/rollback.
+  @param thd                The thread whose transaction should be flushed
+  @param cache_data         Pointer to the cache
+  @param end_ev             The end event either commit/rollback
+  @param is_transactional   The type of the cache: transactional or
+                            non-transactional
 
   @return
-    nonzero if an error pops up when flushing the transactional cache.
+    nonzero if an error pops up when flushing the cache.
 */
-static int
-binlog_flush_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr,
-                       Log_event *end_ev)
+static inline int
+binlog_flush_cache(THD *thd, binlog_cache_data* cache_data, Log_event *end_evt,
+                   bool is_transactional)
 {
-  DBUG_ENTER("binlog_flush_trx_cache");
-  int error=0;
-  IO_CACHE *cache_log= &cache_mngr->trx_cache.cache_log;
-
-  /*
-    This function handles transactional changes and as such
-    this flag equals to true.
-  */
-  bool const is_transactional= TRUE;
-
-  if (thd->binlog_flush_pending_rows_event(TRUE, is_transactional))
-    DBUG_RETURN(1);
-  /*
-    Doing a commit or a rollback including non-transactional tables,
-    i.e., ending a transaction where we might write the transaction
-    cache to the binary log.
-
-    We can always end the statement when ending a transaction since
-    transactions are not allowed inside stored functions. If they
-    were, we would have to ensure that we're not ending a statement
-    inside a stored function.
-  */
-  error= mysql_bin_log.write(thd, &cache_mngr->trx_cache.cache_log, end_ev,
-                             cache_mngr->trx_cache.has_incident());
-  cache_mngr->reset_cache(&cache_mngr->trx_cache);
+  DBUG_ENTER("binlog_flush_cache");
+  int error= 0;
 
-  statistic_increment(binlog_cache_use, &LOCK_status);
-  if (cache_log->disk_writes != 0)
+  if (!cache_data->empty())
   {
-    statistic_increment(binlog_cache_disk_use, &LOCK_status);
-    cache_log->disk_writes= 0;
+    if (thd->binlog_flush_pending_rows_event(TRUE, is_transactional))
+      DBUG_RETURN(1);
+    /*
+      Doing a commit or a rollback including non-transactional tables,
+      i.e., ending a transaction where we might write the transaction
+      cache to the binary log.
+
+      We can always end the statement when ending a transaction since
+      transactions are not allowed inside stored functions. If they
+      were, we would have to ensure that we're not ending a statement
+      inside a stored function.
+    */
+    error= mysql_bin_log.write(thd, &cache_data->cache_log, end_evt,
+                               cache_data->has_incident());
   }
+  cache_data->reset();
 
-  DBUG_ASSERT(cache_mngr->trx_cache.empty());
+  DBUG_ASSERT(cache_data->empty());
   DBUG_RETURN(error);
 }
 
+/**
+  This function flushes the stmt-cache upon commit.
+
+  @param thd                The thread whose transaction should be flushed
+  @param cache_mngr         Pointer to the cache manager
+
+  @return
+    nonzero if an error pops up when flushing the cache.
+*/
+static inline int
+binlog_commit_flush_stmt_cache(THD *thd,
+                               binlog_cache_mngr *cache_mngr)
+{
+  Query_log_event end_evt(thd, STRING_WITH_LEN("COMMIT"),
+                          FALSE, FALSE, TRUE, 0);
+  return (binlog_flush_cache(thd, &cache_mngr->stmt_cache, &end_evt,
+                             FALSE));
+}
+
+/**
+  This function flushes the trx-cache upon commit.
+
+  @param thd                The thread whose transaction should be flushed
+  @param cache_mngr         Pointer to the cache manager
+
+  @return
+    nonzero if an error pops up when flushing the cache.
+*/
+static inline int
+binlog_commit_flush_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr)
+{
+  Query_log_event end_evt(thd, STRING_WITH_LEN("COMMIT"),
+                          TRUE, FALSE, TRUE, 0);
+  return (binlog_flush_cache(thd, &cache_mngr->trx_cache, &end_evt,
+                             TRUE));
+}
+
+/**
+  This function flushes the trx-cache upon rollback.
+
+  @param thd                The thread whose transaction should be flushed
+  @param cache_mngr         Pointer to the cache manager
+
+  @return
+    nonzero if an error pops up when flushing the cache.
+*/
+static inline int
+binlog_rollback_flush_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr)
+{
+  Query_log_event end_evt(thd, STRING_WITH_LEN("ROLLBACK"),
+                          TRUE, FALSE, TRUE, 0);
+  return (binlog_flush_cache(thd, &cache_mngr->trx_cache, &end_evt,
+                             TRUE));
+}
+
+/**
+  This function flushes the trx-cache upon commit.
+
+  @param thd                The thread whose transaction should be flushed
+  @param cache_mngr         Pointer to the cache manager
+  @param xid                Transaction Id
+
+  @return
+    nonzero if an error pops up when flushing the cache.
+*/
+static inline int
+binlog_commit_flush_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr,
+                              my_xid xid)
+{
+  Xid_log_event end_evt(thd, xid);
+  return (binlog_flush_cache(thd, &cache_mngr->trx_cache, &end_evt,
+                             TRUE));
+}
+
 /**
   This function truncates the transactional cache upon committing or rolling
   back either a transaction or a statement.
@@ -1579,23 +1669,24 @@ binlog_truncate_trx_cache(THD *thd, binlog_cache_mngr *cache_mngr, bool all)
   */
   bool const is_transactional= TRUE;
 
-  DBUG_PRINT("info", ("thd->options={ %s%s}, transaction: %s",
+  DBUG_PRINT("info", ("thd->options={ %s %s}, transaction: %s",
                       FLAGSTR(thd->variables.option_bits, OPTION_NOT_AUTOCOMMIT),
                       FLAGSTR(thd->variables.option_bits, OPTION_BEGIN),
                       all ? "all" : "stmt"));
+
+  thd->binlog_remove_pending_rows_event(TRUE, is_transactional);
   /*
     If rolling back an entire transaction or a single statement not
     inside a transaction, we reset the transaction cache.
   */
-  thd->binlog_remove_pending_rows_event(TRUE, is_transactional);
   if (ending_trans(thd, all))
   {
     if (cache_mngr->trx_cache.has_incident())
       error= mysql_bin_log.write_incident(thd, TRUE);
 
-    cache_mngr->reset_cache(&cache_mngr->trx_cache);
-
     thd->clear_binlog_table_maps();
+
+    cache_mngr->reset_cache(&cache_mngr->trx_cache);
   }
   /*
     If rolling back a statement in a transaction, we truncate the
@@ -1619,51 +1710,6 @@ static int binlog_prepare(handlerton *hton, THD *thd, bool all)
   return 0;
 }
 
-/**
-  This function flushes the non-transactional to the binary log upon
-  committing or rolling back a statement.
-
-  @param thd        The thread whose transaction should be flushed
-  @param cache_mngr Pointer to the cache data to be flushed
-
-  @return
-    nonzero if an error pops up when flushing the non-transactional cache.
-*/
-static int
-binlog_flush_stmt_cache(THD *thd, binlog_cache_mngr *cache_mngr)
-{
-  int error= 0;
-  DBUG_ENTER("binlog_flush_stmt_cache");
-  /*
-    If we are flushing the statement cache, it means that the changes get
-    through otherwise the cache is empty and this routine should not be called.
-  */
-  DBUG_ASSERT(cache_mngr->stmt_cache.has_incident() == FALSE);
-  /*
-    This function handles non-transactional changes and as such this flag equals
-    to false.
-  */
-  bool const is_transactional= FALSE;
-  IO_CACHE *cache_log= &cache_mngr->stmt_cache.cache_log;
-
-  if (thd->binlog_flush_pending_rows_event(TRUE, is_transactional))
-    DBUG_RETURN(1);
-
-  Query_log_event qev(thd, STRING_WITH_LEN("COMMIT"), TRUE, FALSE, TRUE, 0);
-  if ((error= mysql_bin_log.write(thd, cache_log, &qev,
-                                  cache_mngr->stmt_cache.has_incident())))
-    DBUG_RETURN(error);
-  cache_mngr->reset_cache(&cache_mngr->stmt_cache);
-
-  statistic_increment(binlog_cache_use, &LOCK_status);
-  if (cache_log->disk_writes != 0)
-  {
-    statistic_increment(binlog_cache_disk_use, &LOCK_status);
-    cache_log->disk_writes= 0;
-  }
-  DBUG_RETURN(error);
-}
-
 /**
   This function is called once after each statement.
 
@@ -1692,7 +1738,7 @@ static int binlog_commit(handlerton *hton, THD *thd, bool all)
 
   if (!cache_mngr->stmt_cache.empty())
   {
-    binlog_flush_stmt_cache(thd, cache_mngr);
+    error= binlog_commit_flush_stmt_cache(thd, cache_mngr);
   }
 
   if (cache_mngr->trx_cache.empty())
@@ -1701,7 +1747,7 @@ static int binlog_commit(handlerton *hton, THD *thd, bool all)
       we're here because cache_log was flushed in MYSQL_BIN_LOG::log_xid()
     */
     cache_mngr->reset_cache(&cache_mngr->trx_cache);
-    DBUG_RETURN(0);
+    DBUG_RETURN(error);
   }
 
   /*
@@ -1710,17 +1756,15 @@ static int binlog_commit(handlerton *hton, THD *thd, bool all)
      - We are in a transaction and a full transaction is committed.
     Otherwise, we accumulate the changes.
   */
-  if (ending_trans(thd, all))
-  {
-    Query_log_event qev(thd, STRING_WITH_LEN("COMMIT"), TRUE, FALSE, TRUE, 0);
-    error= binlog_flush_trx_cache(thd, cache_mngr, &qev);
-  }
+  if (!error && ending_trans(thd, all))
+    error= binlog_commit_flush_trx_cache(thd, cache_mngr);
 
   /*
     This is part of the stmt rollback.
   */
   if (!all)
     cache_mngr->trx_cache.set_prev_position(MY_OFF_T_UNDEF);
+
   DBUG_RETURN(error);
 }
 
@@ -1737,7 +1781,7 @@ static int binlog_commit(handlerton *hton, THD *thd, bool all)
 static int binlog_rollback(handlerton *hton, THD *thd, bool all)
 {
   DBUG_ENTER("binlog_rollback");
-  int error=0;
+  int error= 0;
   binlog_cache_mngr *const cache_mngr=
     (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
 
@@ -1757,16 +1801,16 @@ static int binlog_rollback(handlerton *hton, THD *thd, bool all)
   }
   else if (!cache_mngr->stmt_cache.empty())
   {
-    binlog_flush_stmt_cache(thd, cache_mngr);
+    error= binlog_commit_flush_stmt_cache(thd, cache_mngr);
   }
 
   if (cache_mngr->trx_cache.empty())
   {
-    /* 
+    /*
       we're here because cache_log was flushed in MYSQL_BIN_LOG::log_xid()
     */
     cache_mngr->reset_cache(&cache_mngr->trx_cache);
-    DBUG_RETURN(0);
+    DBUG_RETURN(error);
   }
 
   if (mysql_bin_log.check_write_error(thd))
@@ -1782,9 +1826,9 @@ static int binlog_rollback(handlerton *hton, THD *thd, bool all)
       We reach this point if the effect of a statement did not properly get into
       a cache and need to be rolled back.
     */
-    error= binlog_truncate_trx_cache(thd, cache_mngr, all);
+    error |= binlog_truncate_trx_cache(thd, cache_mngr, all);
   }
-  else
+  else if (!error)
   {  
     /*
       We flush the cache wrapped in a beging/rollback if:
@@ -1796,7 +1840,6 @@ static int binlog_rollback(handlerton *hton, THD *thd, bool all)
         . the format is MIXED, non-trans table was updated and
           aborting a single statement transaction;
     */
-
     if (ending_trans(thd, all) &&
         ((thd->variables.option_bits & OPTION_KEEP_LOG) ||
          (trans_has_updated_non_trans_table(thd) &&
@@ -1806,10 +1849,7 @@ static int binlog_rollback(handlerton *hton, THD *thd, bool all)
          (trans_has_updated_non_trans_table(thd) &&
           ending_single_stmt_trans(thd,all) &&
           thd->variables.binlog_format == BINLOG_FORMAT_MIXED)))
-    {
-      Query_log_event qev(thd, STRING_WITH_LEN("ROLLBACK"), TRUE, FALSE, TRUE, 0);
-      error= binlog_flush_trx_cache(thd, cache_mngr, &qev);
-    }
+      error= binlog_rollback_flush_trx_cache(thd, cache_mngr);
     /*
       Truncate the cache if:
         . aborting a single or multi-statement transaction or;
@@ -1832,7 +1872,8 @@ static int binlog_rollback(handlerton *hton, THD *thd, bool all)
     This is part of the stmt rollback.
   */
   if (!all)
-    cache_mngr->trx_cache.set_prev_position(MY_OFF_T_UNDEF); 
+    cache_mngr->trx_cache.set_prev_position(MY_OFF_T_UNDEF);
+
   DBUG_RETURN(error);
 }
 
@@ -6309,15 +6350,14 @@ void TC_LOG_BINLOG::close()
 int TC_LOG_BINLOG::log_xid(THD *thd, my_xid xid)
 {
   DBUG_ENTER("TC_LOG_BINLOG::log");
-  Xid_log_event xle(thd, xid);
   binlog_cache_mngr *cache_mngr=
     (binlog_cache_mngr*) thd_get_ha_data(thd, binlog_hton);
   /*
     We always commit the entire transaction when writing an XID. Also
     note that the return value is inverted.
    */
-  DBUG_RETURN(!binlog_flush_stmt_cache(thd, cache_mngr) &&
-              !binlog_flush_trx_cache(thd, cache_mngr, &xle));
+  DBUG_RETURN(!binlog_commit_flush_stmt_cache(thd, cache_mngr) &&
+              !binlog_commit_flush_trx_cache(thd, cache_mngr, xid));
 }
 
 void TC_LOG_BINLOG::unlog(ulong cookie, my_xid xid)

sql/log_event.h

@@ -2506,7 +2506,7 @@ class Xid_log_event: public Log_event
    my_xid xid;
 
 #ifdef MYSQL_SERVER
-  Xid_log_event(THD* thd_arg, my_xid x): Log_event(thd_arg,0,0), xid(x) {}
+  Xid_log_event(THD* thd_arg, my_xid x): Log_event(thd_arg, 0, TRUE), xid(x) {}
 #ifdef HAVE_REPLICATION
   void pack_info(Protocol* protocol);
 #endif /* HAVE_REPLICATION */