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

@@ -0,0 +1,195 @@
+# 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

@@ -1,41 +0,0 @@
-# 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

@@ -1,25 +0,0 @@
-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

@@ -0,0 +1,60 @@
+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

@@ -0,0 +1,60 @@
+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

@@ -1,25 +0,0 @@
-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

@@ -0,0 +1,60 @@
+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

@@ -1,25 +0,0 @@
-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_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_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_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