--log-slave-updates is OFF but some updates are still logged to the slave binary log?
Posted
by
quanta
on Server Fault
See other posts from Server Fault
or by quanta
Published on 2012-04-04T12:10:35Z
Indexed on
2012/04/05
5:32 UTC
Read the original article
Hit count: 810
MySQL version 5.5.14
According to the document, by the default, slave does not log to its binary log any updates that are received from a master server.
Here are my config. on the slave:
# egrep 'bin|slave' /etc/my.cnf
relay-log=mysqld-relay-bin
log-bin = /var/log/mysql/mysql-bin
binlog-format=MIXED
sync_binlog = 1
log-bin-trust-function-creators = 1
mysql> show global variables like 'log_slave%';
+-------------------+-------+
| Variable_name | Value |
+-------------------+-------+
| log_slave_updates | OFF |
+-------------------+-------+
1 row in set (0.01 sec)
mysql> select @@log_slave_updates;
+---------------------+
| @@log_slave_updates |
+---------------------+
| 0 |
+---------------------+
1 row in set (0.00 sec)
but slave still logs the some changes to its binary logs, let's see the file size:
-rw-rw---- 1 mysql mysql 37M Apr 1 01:00 /var/log/mysql/mysql-bin.001256
-rw-rw---- 1 mysql mysql 25M Apr 2 01:00 /var/log/mysql/mysql-bin.001257
-rw-rw---- 1 mysql mysql 46M Apr 3 01:00 /var/log/mysql/mysql-bin.001258
-rw-rw---- 1 mysql mysql 115M Apr 4 01:00 /var/log/mysql/mysql-bin.001259
-rw-rw---- 1 mysql mysql 105M Apr 4 18:54 /var/log/mysql/mysql-bin.001260
and the sample query when reading these binary files with mysqlbinlog
utility:
#120404 19:08:57 server id 3 end_log_pos 110324763 Query thread_id=382435 exec_time=0 error_code=0
SET TIMESTAMP=1333541337/*!*/;
INSERT INTO norep_SplitValues VALUES ( NAME_CONST('cur_string',_utf8'118212' COLLATE 'utf8_general_ci'))
/*!*/;
# at 110324763
Did I miss something?
Reply to @RolandoMySQLDBA:
If replication brought this over, then the same query has to be in the relay logs. Please go find the relay log that has the INSERT query with the same TIMESTAMP (1333541337).
There is no such query with the same TIMESTAMP in the relay logs.
If you cannot find it in the relay logs, then look and see if Infobright is posting the INSERT query. In that instance, the INSERT should be recorded in the binary logs of the Slave.
Looking more deeply into the binary logs, I see that almost of the queries are CREATE/INSERT/UPDATE/DROP "temporary" tables, something like this:
# at 123873315
#120405 0:42:04 server id 3 end_log_pos 123873618 Query thread_id=395373 exec_time=0 error_code=0
SET TIMESTAMP=1333561324/*!*/;
SET @@session.pseudo_thread_id=395373/*!*/;
CREATE TEMPORARY TABLE `norep_tmpcampaign` (
`campaignid` INTEGER(11) NOT NULL DEFAULT '0' ,
`status` INTEGER(11) NOT NULL DEFAULT '0' ,
`updated` DATETIME,
KEY `campaignid` (`campaignid`)
)ENGINE=MEMORY
/*!*/;
# at 123873618
#120405 0:42:04 server id 3 end_log_pos 123873755 Query thread_id=395373 exec_time=0 error_code=0
SET TIMESTAMP=1333561324/*!*/;
DROP TABLE IF EXISTS `norep_tmpcampaign1` /* generated by server */
"temporary" here means that they are dropped after calculation is done. I also tells the slave not to replicate any statement matches the norep_
wildcard pattern:
replicate-wild-ignore-table=%.norep_%
But there is an exception table in the binary logs:
# at 123828094
#120405 0:37:21 server id 3 end_log_pos 123828495 Query thread_id=395209 exec_time=0 error_code=0
SET TIMESTAMP=1333561041/*!*/;
INSERT INTO sessions (SessionId, ApplicationName, Created, Expires, LockDate, LockId, Timeout, Locked, SessionItems, Fla
gs) Values('pgv2exo4y4vo4ccz44vwznu0', '/', '2012-04-05 00:37:21', '2012-04-05 00:57:21', '2012-04-05 00:37:21', 0, 20,
0, 'AwAAAP////8IdXNlcm5hbWUGdXNlcmlkCHBlcm1pdGlkAgAAAAQAAAAGAAAAAQABAAEA', 0)
/*!*/;
Description:
mysql> desc reportingdb.sessions;
+-----------------+------------------+------+-----+---------------------+-------+
| Field | Type | Null | Key | Default | Extra |
+-----------------+------------------+------+-----+---------------------+-------+
| SessionId | varchar(64) | NO | PRI | | |
| ApplicationName | varchar(255) | NO | | | |
| Created | timestamp | NO | | 0000-00-00 00:00:00 | |
| Expires | timestamp | NO | | 0000-00-00 00:00:00 | |
| LockDate | timestamp | NO | | 0000-00-00 00:00:00 | |
| LockId | int(11) unsigned | NO | | NULL | |
| Timeout | int(11) unsigned | NO | | NULL | |
| Locked | bit(1) | NO | | NULL | |
| SessionItems | varchar(255) | YES | | NULL | |
| Flags | int(11) | NO | | NULL | |
+-----------------+------------------+------+-----+---------------------+-------+
I'm sure all these queries are posting by MySQL, not Infobright:
$ mysql-ib -u root -p
Enter password:
Welcome to the MySQL monitor. Commands end with ; or \g.
Your MySQL connection id is 48971
Server version: 5.1.40 build number (revision)=IB_4.0.5_r15240_15370(ice) (static)
Type 'help;' or '\h' for help. Type '\c' to clear the current input statement.
mysql> select * from information_schema.tables where table_name='sessions';
Empty set (0.02 sec)
I've been trying some INSERT/UPDATE queries with testing tables on the master, it is copied to the relay logs, not binary logs on slave:
# at 311664029
#120405 0:15:23 server id 1 end_log_pos 311664006 Query thread_id=10458250 exec_time=0 error_code=0
use testuser/*!*/;
SET TIMESTAMP=1333559723/*!*/;
update users set email2='[email protected]' where id=22
/*!*/;
Pay attention to the server id
, in the relay logs, server id is master's (1) and in the binary log, server id is slave's (3 in this case).
Reply to @RolandoMySQLDBA: Thu Apr 5 10:06:00 ICT 2012
Run
CREATE DATABASE quantatest;
on the Master now, please. Tell me ifCREATE DATABASE quantatest;
showed up in the Slave's Binary Logs.
As I said above:
I've been trying some INSERT/UPDATE queries with testing tables on the master, it is copied to the relay logs, not binary logs
and you can guess, IO thread copied it to the relay logs, not binary logs.
#120405 10:07:25 server id 1 end_log_pos 347573819 Query thread_id=10480775 exec_time=0 error_code=0
SET TIMESTAMP=1333595245/*!*/;
/*!\C latin1 *//*!*/;
SET @@session.character_set_client=8,@@session.collation_connection=8,@@session.collation_server=8/*!*/;
create database quantatest
/*!*/;
The question must probably change to: why some update queries still logged to the slave binary logs althrough --log-slave-updates
is disabled? Where they come from?
Here are few last:
/*!*/;
# at 27492197
#120405 10:12:45 server id 3 end_log_pos 27492370 Query thread_id=410353 exec_time=0 error_code=0
SET TIMESTAMP=1333595565/*!*/;
CREATE TEMPORARY TABLE norep_SplitValues (
value VARCHAR(1000) NOT NULL
) ENGINE=MEMORY
/*!*/;
# at 27492370
#120405 10:12:45 server id 3 end_log_pos 27492445 Query thread_id=410353 exec_time=0 error_code=0
SET TIMESTAMP=1333595565/*!*/;
BEGIN
/*!*/;
# at 27492445
#120405 10:12:45 server id 3 end_log_pos 27492619 Query thread_id=410353 exec_time=0 error_code=0
SET TIMESTAMP=1333595565/*!*/;
INSERT INTO norep_SplitValues VALUES ( NAME_CONST('cur_string',_utf8'119577' COLLATE 'utf8_general_ci'))
/*!*/;
# at 27492619
#120405 10:12:45 server id 3 end_log_pos 27492695 Query thread_id=410353 exec_time=0 error_code=0
SET TIMESTAMP=1333595565/*!*/;
COMMIT
/*!*/;
# at 27492918
#120405 10:12:46 server id 3 end_log_pos 27493115 Query thread_id=410353 exec_time=0 error_code=0
SET TIMESTAMP=1333595566/*!*/;
SELECT `reportingdb`.`selfserving_get_locationad`(_utf8'3' COLLATE 'utf8_general_ci',_utf8'' COLLATE 'utf8_general_ci')
/*!*/;
# at 27493199
#120405 10:12:46 server id 3 end_log_pos 27493353 Query thread_id=410353 exec_time=0 error_code=0
SET TIMESTAMP=1333595566/*!*/;
/*!\C utf8 *//*!*/;
SET @@session.character_set_client=33,@@session.collation_connection=33,@@session.collation_server=8/*!*/;
DROP TEMPORARY TABLE IF EXISTS `norep_SplitValues` /* generated by server */
/*!*/;
© Server Fault or respective owner