MySQL Bugs: #40146: log_slave_updates uses MIXED mode for binlog regardless of binlog

Bug #40146	log_slave_updates uses MIXED mode for binlog regardless of binlog_format
Submitted:	19 Oct 2008 16:51	Modified:	24 Mar 2009 14:42
Reporter:	Giuseppe Maxia	Email Updates:
Status:	Not a Bug	Impact on me:	None
Category:	MySQL Server: Row Based Replication ( RBR )	Severity:	S1 (Critical)
Version:	5.1.29, 5.1, 6.0 bzr	OS:	Any
Assigned to:	Alfranio Tavares Correia Junior	CPU Architecture:	Any
Tags:	mixed mode, RBR, relay, replication, statement mode

Description:
When using a relay slave, with the "log_slave_updates" option, and the binlog_format set to 'STATEMENT', the relay slave uses MIXED mode to fill the binary log.

For example, if the master uses 
INSERT INTO t1 values (@@server_id)

the slave relay log gets the statement unchanged
the slave binary log, instead, gets a RBR statement.

How to repeat:
using MySQL Sandbox 2.0.12
./make_replication_sandbox ~/path/to/mysql-5.1.29-YOUR_OS.tar.gz

cd $HOME/sandboxes/rsandbox_5_1_29
echo log_slave_updates >> node2/my.sandbox.cnf
./node2/restart
./use_all "set global binlog_format=statement"

./m -e 'create table test.t1 (i int)'
./m -e 'insert into test.t1 values (@@server_id)'

# inspect binary log and relay log of node2 relay slave

I found the pattern.
The mismatch happens if this sequence happens:
set global binlog_format=mixed;
start slave;
set global binlog_format=statement;

This latest command influences all *new* connections. However, the SQL_THREAD is already running, and this command does not influence it.
So the command is inherited from the master in statement format, and then passed to the SQL_THREAD, which is still in MIXED format.

The above behavior is logical, and it perhaps described in the manual, but it is a bug nonetheless. If I run "SET GLOBAL binlog_format=STATEMENT", my goal is to influence the binlog, which stays unaffected, unless I stop and start the slave.

Workaround: when issuing a "SET GLOBAL binlog_format=STATEMENT", you also need to stop and start the slave.

Thank you for the report.

Manual is clear about this:

In addition to switching the logging format manually, a slave server may switch the format automatically. This happens when the server is running in either STATEMENT or MIXED format and encounters a row in the binary log that is written in ROW logging format. In that case, the slave switches to row-based replication temporarily for that event, and switches back to the previous format afterwards. 

(http://dev.mysql.com/doc/refman/5.1/en/binary-log-setting.html)

So I can verify this as feature request only. Is it OK for you or bug should be closed as "Not a Bug"?

Sveta,
The manual page that you refers to is not the behavior I am describing here. 
This problem only happens in a relay slave, i.e. a slave that is also master of other slaves.
in this case, we have statement based instructions coming from the master (so the manual page does not apply) and before the slave processes such statements, there is an explicit set of the binlog_format to 'STATEMENT'.
What happens is that the slave does not change from MIXED to STATEMENT for the SQL_THREAD which is running in background, so when the SQL command comes, it is processed as STATEMENT, but it is logged using MIXED mode.

The matter for complaint is that "SET GLOBAL binlog_format=STATEMENT" does not apply to the SQL_THREAD which is already running.
Compare this behavior with other global settings. If you set "general_log", it applies immediately to all sessions, open and closed ones.

HOW TO REPEAT: (updated) 

using MySQL Sandbox 2.0.12
./make_replication_sandbox ~/path/to/mysql-5.1.29-YOUR_OS.tar.gz

cd $HOME/sandboxes/rsandbox_5_1_29
echo log_slave_updates >> node2/my.sandbox.cnf
echo binlog_format=mixed >> node2/my.sandbox.cnf
./node2/restart

./use_all "set global binlog_format=statement"

./m -e 'create table test.t1 (i int)'
./m -e 'insert into test.t1 values (@@server_id)'

# inspect binary log and relay log of node2 relay slave

Thank you for the feedback.

Interesting if restart slave query would be written in statement format independently from master settings.

Test case for MySQL test suite:

--source include/master-slave.inc

connection slave;

stop slave;

#connection master;
#set global binlog_format=row;

#connection slave;

set global binlog_format=mixed;
start slave;
set global binlog_format=statement;

#stop slave;
#start slave;

connection master;

create table t1(id int);
INSERT INTO t1 values (@@server_id);

sleep 1;

connection slave;

flush logs;

--exec $MYSQL_BINLOG $MYSQL_TEST_DIR/var/log/slave-bin.000001

Option file:
--log-bin --log-slave-updates

I realize the problem, but this is how threads in general, and the slave thread in particular, works: for variable that have both a session and global version, global settings are copied into any starting threads, but does not affect running threads.

To do it another way would be a recipe for disaster: if changing a global variable affect all clients that are connected, there will be some surprises when a global variable changes values. This could, for example, cause threads that are currently running with one setting of SQL_MODE to suddenly stop working as expected since the value is changed through another thread setting the global value of the variable.

The comparison with 'general_log' is not adequate since that is a global variable *only*; comparing the behavior with 'tx_isolation' is probably a better match, since that does not affect the running thread either but should conceivably, from a users perspective, affect the SQL thread immediately.

The problem is that users are not treating the SQL thread as a separate session, which it is, and that normal session rules apply for it. However, using the global variable to set the value of the slave threads session variable has two drawbacks:

a. It affects all threads, not just the slave threads. So assuming that the
slave thread need a setting different from all the other threads, the server
will have to be brought off-line to change to value of the slave threads
variables.

b. It is necessary to stop and start the slave threads for the settings to
take effect.

I would say that there are two ways to fix this:

1. Either make the SQL thread special in that it will update the session
variable on-the-fly when the global variable changes.

This solution will be problematic to maintain since it requires the slave
thread to check if any server variables have changed between the execution
of each "statement". This can of course be made to be relatively cheap by
introducing a "version" for the server variables and stepping that every
time a variable is changed, but it will nevertheless affect execution.

Also, it still suffers from the (a) problem above.

2. Introduce a special keyword to allow the slave session variables to be set
from another session, for example "set @@slave.binlog_format = mixed".

I would prefer the second approach, since it solves both (a) and (b).

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/69638

2841 Alfranio Correia 2009-03-18
BUG#40146 log_slave_updates uses MIXED mode for binlog regardless of binlog_format

It was not possible to check or change a SQL Thread's session variable. In particular,
to change binlog_format, one needed to change its global value, stop and restart the
replication. This approach had two drawbacks. It required to globally change a value
of a variable thus affecting not only the SQL Thread but any new thread. Besides, it
was necessary to stop the replication for a few seconds to inherit the new value.

This patch fixes this issues by introducing the following commands:
SET RUNNING_SLAVE <variable> = <value>;
SHOW RUNNING_SLAVE like <variable>;

The variants of the commend as described in the manual are also accepted. The user
issuing the command and the user on behalf of which the SQL Thread is running must
have the appropriate privileges to successfully execute this command. In particular,
to change the binlog_format both need SUPER privilege.

@sql/lex:
introduces a new token.
@sql/mysql_priv.h
introduces a new type.
@sql/set_var.cc and @sql/set_var.h
checks when the new type is used and instead of changing
information on the current thread, the SQL Thread has
its information changed.
@sql/sql_lex.cc
updates a comment.
@sql/slq_show.cc
checks when the new type is used and instead of retrieving
information on the current thread, the SQL Thread has
its information retrieved.
@sql/sql_yacc.yy
changes the grammar.

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/69642

2842 Alfranio Correia	2009-03-18
      BUG#40146 log_slave_updates uses MIXED mode for binlog regardless of binlog_format
      
      Added test case.

Docs update: http://lists.mysql.com/commits/70221

Closed as !BUG per discussion with RPL devs.