log_slow_slave_statements doesn't work

[Aleksandr Kuzminsky]

Queries issued on a master are not logged on a slave's slow log.

From mysq-test test(microslow_innodb_log_slow_slave_statements):
..
connection master;
CREATE TABLE t1(
  id INT PRIMARY KEY NOT NULL AUTO_INCREMENT,
  name VARCHAR(255)
  );
INSERT INTO t1(name) VALUES('aaa');

connection slave;
SELECT * FROM t1;
...

The test was run as:
./mtr --record --mysqld=--log_slow_slave_statements=1 microslow_innodb_log_slow_slave_statements

The slave's slow log(CREATE and INSERT are missing in it):
SET long_query_time=0;
# User@Host: root[root] @ localhost [127.0.0.1]
# Thread_id: 2 Schema: test
# Query_time: 0.000401 Lock_time: 0.000289 Rows_sent: 0 Rows_examined: 0 Rows_affected: 0 Rows_read: 1
SET timestamp=1242924506;
SELECT * FROM t1;

[Vadim Tkachenko (vadim-tk)]

Please specify version you are testing.
If this is for 5.1 - please report the same bug for official MySQL 5.1, as
this is standard feature.

On Thu, May 21, 2009 at 9:56 AM, Aleksandr Kuzminsky <
<email address hidden>> wrote:

> Public bug reported:
>
> Queries issued on a master are not logged on a slave's slow log.
>
> >From mysq-test test(microslow_innodb_log_slow_slave_statements):
> ..
> connection master;
> CREATE TABLE t1(
> id INT PRIMARY KEY NOT NULL AUTO_INCREMENT,
> name VARCHAR(255)
> );
> INSERT INTO t1(name) VALUES('aaa');
>
> connection slave;
> SELECT * FROM t1;
> ...
>
> The test was run as:
> ./mtr --record --mysqld=--log_slow_slave_statements=1
> microslow_innodb_log_slow_slave_statements
>
> The slave's slow log(CREATE and INSERT are missing in it):
> SET long_query_time=0;
> # User@Host: root[root] @ localhost [127.0.0.1]
> # Thread_id: 2 Schema: test
> # Query_time: 0.000401 Lock_time: 0.000289 Rows_sent: 0 Rows_examined: 0
> Rows_affected: 0 Rows_read: 1
> SET timestamp=1242924506;
> SELECT * FROM t1;
>
> ** Affects: percona-patches
> Importance: Undecided
> Status: New
>
> --
> log_slow_slave_statements doesn't work
> https://bugs.launchpad.net/bugs/379115
> You received this bug notification because you are a member of Percona
> developers, which is the registrant for Percona patches.
>
> Status in Patches for MySQL by Percona: New
>
> Bug description:
> Queries issued on a master are not logged on a slave's slow log.
>
> >From mysq-test test(microslow_innodb_log_slow_slave_statements):
> ..
> connection master;
> CREATE TABLE t1(
> id INT PRIMARY KEY NOT NULL AUTO_INCREMENT,
> name VARCHAR(255)
> );
> INSERT INTO t1(name) VALUES('aaa');
>
> connection slave;
> SELECT * FROM t1;
> ...
>
> The test was run as:
> ./mtr --record --mysqld=--log_slow_slave_statements=1
> microslow_innodb_log_slow_slave_statements
>
> The slave's slow log(CREATE and INSERT are missing in it):
> SET long_query_time=0;
> # User@Host: root[root] @ localhost [127.0.0.1]
> # Thread_id: 2 Schema: test
> # Query_time: 0.000401 Lock_time: 0.000289 Rows_sent: 0 Rows_examined: 0
> Rows_affected: 0 Rows_read: 1
> SET timestamp=1242924506;
> SELECT * FROM t1;
>

[Aleksandr Kuzminsky (akuzminsky)]

Sorry version gone during copy&paste.
It is applicable to lp:~percona-dev/percona-patches/5.1.34

[Vadim Tkachenko (vadim-tk)]

5.1.34

[Yasufumi Kinoshita (yasufumi-kinoshita)]

For 5.1.34, log_slow_slave_statements is native option of MySQL.
http://dev.mysql.com/doc/refman/5.1/en/replication-options-slave.html#option_mysqld_log-slow-slave-statements

I think the patches of 5.1.34 does not touch the option....
I will investigate it. So, where the test-script is?

[Yasufumi Kinoshita (yasufumi-kinoshita)]

http://bazaar.launchpad.net/~percona-dev/percona-patches/5.1.34/revision/6

This may be bug of MySQL-5.1.34...

[Yasufumi Kinoshita (yasufumi-kinoshita)]

If you want to log "CREATE TABLE" here, log-slow-admin-statements option is also needed.

[Aleksandr Kuzminsky (akuzminsky)]

-----BEGIN PGP SIGNED MESSAGE-----
Hash: SHA1

Yasufumi Kinoshita schrieb:
> For 5.1.34, log_slow_slave_statements is native option of MySQL.
> http://dev.mysql.com/doc/refman/5.1/en/replication-options-slave.html#option_mysqld_log-slow-slave-statements
>
> I think the patches of 5.1.34 does not touch the option....
> I will investigate it. So, where the test-script is?
>

Yasufumi,

Here is a draft on the test, which can be used. If success - you have to
see "INSERT" in a slow log.

t/microslow_innodb_log_slow_slave_statements.test

- --source include/master-slave.inc

connection master;
- --disable_warnings
DROP TABLE IF EXISTS t1;
- --enable_warnings

connection slave;

SET @old_slow_query_log=@@slow_query_log;
SET @old_long_query_time=@@long_query_time;

SET GLOBAL slow_query_log=on;
SET long_query_time=0;
SET log_slow_slave_statements=1;

connection master;
CREATE TABLE t1(
  id INT PRIMARY KEY NOT NULL AUTO_INCREMENT,
  name VARCHAR(255)
  );
INSERT INTO t1(name) VALUES('aaa');

connection slave;
SELECT * FROM t1;

SELECT @@slow_query_log_file;
SET GLOBAL slow_query_log=@old_slow_query_log;
SET long_query_time=@old_long_query_time;
#--exec bash -c "cat $f| sed 's/Tcp port: [0-9]*/Tcp port: PORT/' | sed
's/Unix socket: .*/Unix socket: SOCKET/' | sed 's/^\/.*mysqld/mysqld/' |
sed 's/Version: .*/Version: VERSION/' | grep -v '^# Time' | sed 's/^#
Query_time: [0-9]*.[0-9]*/# Query_time: TIME/' | sed 's/Lock_time:
[0-9]*.[0-9]*/Lock_time: TIME/' | sed 's/SET timestamp=[0-9]*;/SET
timestamp=TIME;/'"

connection master;
DROP TABLE t1;
-----BEGIN PGP SIGNATURE-----
Version: GnuPG v1.4.9 (MingW32)
Comment: Using GnuPG with Mozilla - http://enigmail.mozdev.org

iEYEARECAAYFAkoeN3EACgkQQ6p+ZxjCGwVwtACdFWlum2jcr1cV5dq0O6bHiJWt
+jEAnidHc3dwnDJTuajakfFdPgNqi8M3
=Kd2M
-----END PGP SIGNATURE-----