MySQL Bugs: #23890: mysqlbinlog outputs COMMIT unnecessarily when single database is used

Bug #23890	mysqlbinlog outputs COMMIT unnecessarily when single database is used
Submitted:	2 Nov 2006 15:52	Modified:	30 Aug 2009 7:00
Reporter:	James Day	Email Updates:
Status:	Not a Bug	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S3 (Non-critical)
Version:	5.0.27	OS:	Linux (RHES3,Windows)
Assigned to:	Daogang Qu	CPU Architecture:	Any
Tags:	bfsm_2006_12_07

Description:
mysqlbinlog --database=bar N-bin.000003 >003bar.txt

will output all the COMMITs in the binary log even if the database isn't mentioned in the binary log.

How to repeat:
use test
create table foo (foo int, unique key (foo)) engine=innodb;
set autocommit=0;
insert into foo values (1);
commit;
insert into foo values (2);
commit;
insert into foo values (3);
commit;
drop table if exists foo;

Run the equivalent of:

..\bin\mysqlbinlog --database=bar N-bin.000003 >003bar.txt

Produces this filtered binlog output:

/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
# at 4
#061102 15:39:25 server id 5632  end_log_pos 98 	Start: binlog v 4, server v 5.0.27-community-log created 061102 15:39:25 at startup
ROLLBACK;
# at 98
# at 219
# at 287
# at 376
#061102 15:39:37 server id 5632  end_log_pos 403 	Xid = 5
COMMIT;
# at 403
# at 471
# at 560
#061102 15:39:37 server id 5632  end_log_pos 587 	Xid = 7
COMMIT;
# at 587
# at 655
# at 744
#061102 15:39:37 server id 5632  end_log_pos 771 	Xid = 9
COMMIT;
# at 771
# at 858
#061102 15:40:07 server id 5632  end_log_pos 877 	Stop
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;

There's no need for the COMMITs to be here since no statements affecting the selected database are present.

Suggested fix:
Don't emit the COMMITS if no other statements have been processed?

If this is somehow related to http://bugs.mysql.com/27037 (SHOW SLAVE STATUS not returning correct position in 5.0) then severity/priority should be much higher.

This bug isn't directly related to bug #27037 that Arjen mentioned. That one was fixed by the fix for bug #27171.

The N-bin.000003 file can't be found, is it renamed to master-bin.000001 under $MysqlTop/mysql-test/var/mysqld.1/data/ directory on mysql 5.0+ versions?
 
The mysqlbinlog can't be found under \bin directory, is it
put to $MysqlTop\client directory on mysql 5.0+ versions?

N was the name of the computer that was being used to reproduce the problem and file the bug report. You can specify any base file name that you want to use in my.cnf and should do so in production systems so that the binary log can be found if the server name is changed.

mysqlbinlog is normally in the bin directory in a Windows server created with the noinstall installer package. For other systems see: http://dev.mysql.com/doc/refman/5.0/en/installation-layouts.html .

James Day, MySQL Senior Support Engineer, Sun Microsystems

A patch for this bug has been committed. After review, it may
be pushed to the relevant source trees for release in the next
version. You can access the patch from:

  http://lists.mysql.com/commits/80949

2789 Dao-Gang.Qu@sun.com	2009-08-18
      Bug #23890  	mysqlbinlog outputs COMMIT unnecessarily when single database is used
      
      mysqlbinlog --database=bar N-bin.000003 >003bar.txt
      will output all the COMMITs in the binary log even if the database argument 'bar' isn't mentioned 
      in the binary log. The COMMITS isn't associated with database in the binary log, so the COMMITS 
      will be output in any situation.
      
      To fix the problem, we need record and update the using database from context. So that the COMMITs 
      will be output in the following two cases:
      1. The database argument is consistent with the using database.
      2. The database argument is NULL.
     @ client/mysqlbinlog.cc
        Added database_using[] array to record and update the using database from context.

I think we should set its status to Not a bug. Because if we remove the COMMIT from the mysqlbinlog output, the transaction will be more incomplete as the test case showed below. I think the mysqlbinlog should outputs BEGIN in any cases for building a complete transaction. 

Test Result:
daogangq@daogangq-laptop:~/mysql/bzrwork/bug23890/mysql-5.0-bugteam/mysql-test$ ../client/mysqlbinlog --database=test var/log/master-bin.000001
/*!40019 SET @@session.max_insert_delayed_threads=0*/;
/*!50003 SET @OLD_COMPLETION_TYPE=@@COMPLETION_TYPE,COMPLETION_TYPE=0*/;
DELIMITER /*!*/;
# at 4
#090818 23:43:20 server id 1  end_log_pos 98 	Start: binlog v 4, server v 5.0.85-debug-log created 090818 23:43:20 at startup
ROLLBACK/*!*/;
# at 98
#090818 23:43:20 server id 1  end_log_pos 244 	Query	thread_id=1	exec_time=0	error_code=0
use test/*!*/;
SET TIMESTAMP=1250610200/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=1, @@session.unique_checks=1/*!*/;
SET @@session.sql_mode=0/*!*/;
/*!\C latin1 *//*!*/;
SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/*!*/;
create table test.t1(n int, bar int auto_increment, unique key (bar)) engine=innodb
/*!*/;
# at 244
# at 388
# at 457
# at 485
#090818 23:43:20 server id 1  end_log_pos 577 	Query	thread_id=1	exec_time=0	error_code=0
SET TIMESTAMP=1250610200/*!*/;
insert into t1 (n) values (1)
/*!*/;
# at 577
#090818 23:43:20 server id 1  end_log_pos 683 	Query	thread_id=1	exec_time=0	error_code=0
SET TIMESTAMP=1250610200/*!*/;
insert into t1 (n, bar) values (2, bar+100)
/*!*/;
# at 683
#090818 23:43:20 server id 1  end_log_pos 711 	Intvar
SET INSERT_ID=1/*!*/;
# at 711
# at 804
#090818 23:43:20 server id 1  end_log_pos 831 	Xid = 13
COMMIT/*!*/;
# at 831
# at 913
# at 996
#090818 23:43:21 server id 1  end_log_pos 1015 	Stop
DELIMITER ;
# End of log file
ROLLBACK /* added by mysqlbinlog */;
/*!50003 SET COMPLETION_TYPE=@OLD_COMPLETION_TYPE*/;
daogangq@daogangq-laptop:~/mysql/bzrwork/bug23890/mysql-5.0-bugteam/mysql-test$ 

Test Case:
#
# This test case to verify if the transaction is complete for 'test' database.`
#
-- source include/have_log_bin.inc
-- source include/have_innodb.inc

--disable_warnings
drop table if exists t1;
--enable_warnings

set @ac = @@autocommit;

set autocommit= 0;
reset master;

use test;
create table test.t1(n int, bar int auto_increment, unique key (bar)) engine=innodb;
use mysql;
create table t2(m int, bar1 int auto_increment, unique key (bar1)) engine=innodb;

begin;
use test;
insert into t1 (n) values (1);

insert into t1 (n, bar) values (2, bar+100);

use mysql;
insert into t2 (m) values (1);
commit;

drop table test.t1;
drop table mysql.t2;
set session autocommit = @ac;

It's not a bug base on above analysis and it's unnecessary to get rid of all the COMMITs in the binary log even if the database isn't mentioned in the binary log.

Report a new Bug#46998 for the mysqlbinlog should output BEGIN instead of getting rid of COMMIT if the database is included in a transaction .