Description:
Note about version: We are using Percona-XtraDB-Cluster-5.5.39-25.11 which is based on Percona Server 5.5.39-36.0 which is based on MySQL 5.5.39.
When executing CREATE TABLE IF NOT EXISTS statements simultaneously on a writeable master and a read only host that is slaving from it, some statements are not making it into the binary log on the slave and therefore not slaved to any slaves that host may have.
Database Setup:
Writeable Master <---> Read Only Master ---> Read Only Slave
The writeable master and read only master are in circular replication. Both masters have multiple read only slaves slaving from them.
Query:
CREATE TABLE IF NOT EXISTS foobar ( current_table varchar(255) not null ) engine=innodb
(1) I ran the above query in a tight loop on the writeable master and read only master. Binary logging was enabled on the writeable master and disabled, at the session level, on the read only master. After running for about 2 minutes, the query executed 740556 times on the writeable master and 751450 times on the read only master. I would expect this query to be in the binary log of all hosts precisely 740556 times. The binary logs on the writeable master contained the query 740556 times as expected, however, the binary logs on the read only master contained the query only 740317 times; it missed 239 queries.
(2) I performed the same test running the same query only on the writeable master. The same query was executed 1107942 on the writeable master. As expected the binary logs of both the writeable master and the read only master contained this query precisely 1107942 times.
(3) I also performed a test where I executed different queries following the same execution pattern as test 1, and could not replicate the failure scenario where queries were missed in the read only master's binary log. I tried the following scenarios:
(3a) Create foobar and pre-populate foobar with a value. Then increment the value in a tight loop.
-- Setup --
CREATE TABLE IF NOT EXISTS foobar ( val mediumint(8) unsigned ) engine=innodb
INSERT INTO foobar values (0)
-- End Setup --
-- Loop --
UPDATE foobar SET val = val + 1
-- End Loop --
The update was executed 7842975 times on the writeable master and 7831642 times on the read only master. As expected, the update queries were in both binary logs 7842975 times.
(3b) Create foobar and pre-populate foobar with a value. Then update the value in a tight loop.
-- Setup --
CREATE TABLE IF NOT EXISTS foobar ( val mediumint(8) unsigned ) engine=innodb
INSERT INTO foobar values (42)
-- End Setup --
-- Loop --
UPDATE foobar SET val = 42
-- End Loop --
The update was executed 934580 times on the writeable master and 944056 times on the read only master. As expected, the update queries were in both binary logs 934580 times.
(3c) Create differently named tables in a tight loop on both hosts.
-- Loop Writeable Master --
CREATE TABLE IF NOT EXISTS foobar_rw_$(run_number) ( val tinyint(1) unsigned ) engine=innodb
-- End Loop Writeable Master --
-- Loop Read Only Master --
CREATE TABLE IF NOT EXISTS foobar_ro_$(run_number) ( val tinyint(1) unsigned ) engine=innodb
-- End Loop Read Only Master --
The script created 60212 tables via the writeable master. As expected, all 60212 queries were in both binary logs.
How to repeat:
Set up two hosts in replication, one that is writeable and one that is read only. Enable binary logging on both hosts with log_bin and log_slave_updates.
Run a script on both hosts to run the same CREATE TABLE IF NOT EXISTS query in a tight loop. Below is the ruby script that I used to perform the tests. Set replicate to true on the writeable host, and false on the read only host.
# vim: set ft=ruby :
require 'mysql2'
require 'active_record'
replicate = true
testing_comment = "my_test_run" # unique identifier to identify queries in binary log
query = "CREATE TABLE IF NOT EXISTS foobar ( current_table varchar(255) not null ) engine=innodb"
connection_info = {
:adapter => "mysql2",
:database => db_name,
:host => "127.0.0.1",
:port => db_port,
:username => db_user,
:password => db_password,
:connect_timeout => 60,
:read_timeout => 5,
}
ActiveRecord::Base.establish_connection(connection_info)
puts "Connected to the database"
if !replicate
puts "Disabling binary logging"
ActiveRecord::Base.connection.execute("SET @@sql_log_bin = 0")
end
command = "#{query} /* #{testing_comment} */".strip
puts "Running #{command}"
num_runs = 0
begin
loop do
ActiveRecord::Base.connection.execute(command)
num_runs += 1
end
rescue Exception => e
puts e
end
puts "Done. Ran #{num_runs} times."
Run the script for about 5 minutes before killing it.
Then grep the binary logs on both hosts for the testing_comment in the script above to determine how many of the queries made it to the binary logs:
mysqlbinlog <binary_log> | grep <testing_comment> | wc -l
Suggested fix:
I have no suggested fix because I have no idea why the problem is occurring.
Description: Note about version: We are using Percona-XtraDB-Cluster-5.5.39-25.11 which is based on Percona Server 5.5.39-36.0 which is based on MySQL 5.5.39. When executing CREATE TABLE IF NOT EXISTS statements simultaneously on a writeable master and a read only host that is slaving from it, some statements are not making it into the binary log on the slave and therefore not slaved to any slaves that host may have. Database Setup: Writeable Master <---> Read Only Master ---> Read Only Slave The writeable master and read only master are in circular replication. Both masters have multiple read only slaves slaving from them. Query: CREATE TABLE IF NOT EXISTS foobar ( current_table varchar(255) not null ) engine=innodb (1) I ran the above query in a tight loop on the writeable master and read only master. Binary logging was enabled on the writeable master and disabled, at the session level, on the read only master. After running for about 2 minutes, the query executed 740556 times on the writeable master and 751450 times on the read only master. I would expect this query to be in the binary log of all hosts precisely 740556 times. The binary logs on the writeable master contained the query 740556 times as expected, however, the binary logs on the read only master contained the query only 740317 times; it missed 239 queries. (2) I performed the same test running the same query only on the writeable master. The same query was executed 1107942 on the writeable master. As expected the binary logs of both the writeable master and the read only master contained this query precisely 1107942 times. (3) I also performed a test where I executed different queries following the same execution pattern as test 1, and could not replicate the failure scenario where queries were missed in the read only master's binary log. I tried the following scenarios: (3a) Create foobar and pre-populate foobar with a value. Then increment the value in a tight loop. -- Setup -- CREATE TABLE IF NOT EXISTS foobar ( val mediumint(8) unsigned ) engine=innodb INSERT INTO foobar values (0) -- End Setup -- -- Loop -- UPDATE foobar SET val = val + 1 -- End Loop -- The update was executed 7842975 times on the writeable master and 7831642 times on the read only master. As expected, the update queries were in both binary logs 7842975 times. (3b) Create foobar and pre-populate foobar with a value. Then update the value in a tight loop. -- Setup -- CREATE TABLE IF NOT EXISTS foobar ( val mediumint(8) unsigned ) engine=innodb INSERT INTO foobar values (42) -- End Setup -- -- Loop -- UPDATE foobar SET val = 42 -- End Loop -- The update was executed 934580 times on the writeable master and 944056 times on the read only master. As expected, the update queries were in both binary logs 934580 times. (3c) Create differently named tables in a tight loop on both hosts. -- Loop Writeable Master -- CREATE TABLE IF NOT EXISTS foobar_rw_$(run_number) ( val tinyint(1) unsigned ) engine=innodb -- End Loop Writeable Master -- -- Loop Read Only Master -- CREATE TABLE IF NOT EXISTS foobar_ro_$(run_number) ( val tinyint(1) unsigned ) engine=innodb -- End Loop Read Only Master -- The script created 60212 tables via the writeable master. As expected, all 60212 queries were in both binary logs. How to repeat: Set up two hosts in replication, one that is writeable and one that is read only. Enable binary logging on both hosts with log_bin and log_slave_updates. Run a script on both hosts to run the same CREATE TABLE IF NOT EXISTS query in a tight loop. Below is the ruby script that I used to perform the tests. Set replicate to true on the writeable host, and false on the read only host. # vim: set ft=ruby : require 'mysql2' require 'active_record' replicate = true testing_comment = "my_test_run" # unique identifier to identify queries in binary log query = "CREATE TABLE IF NOT EXISTS foobar ( current_table varchar(255) not null ) engine=innodb" connection_info = { :adapter => "mysql2", :database => db_name, :host => "127.0.0.1", :port => db_port, :username => db_user, :password => db_password, :connect_timeout => 60, :read_timeout => 5, } ActiveRecord::Base.establish_connection(connection_info) puts "Connected to the database" if !replicate puts "Disabling binary logging" ActiveRecord::Base.connection.execute("SET @@sql_log_bin = 0") end command = "#{query} /* #{testing_comment} */".strip puts "Running #{command}" num_runs = 0 begin loop do ActiveRecord::Base.connection.execute(command) num_runs += 1 end rescue Exception => e puts e end puts "Done. Ran #{num_runs} times." Run the script for about 5 minutes before killing it. Then grep the binary logs on both hosts for the testing_comment in the script above to determine how many of the queries made it to the binary logs: mysqlbinlog <binary_log> | grep <testing_comment> | wc -l Suggested fix: I have no suggested fix because I have no idea why the problem is occurring.