diff options
| author | unknown <knielsen@knielsen-hq.org> | 2012-06-22 11:46:28 +0200 |
|---|---|---|
| committer | unknown <knielsen@knielsen-hq.org> | 2012-06-22 11:46:28 +0200 |
| commit | 0697ee265fa4fe4d617dc96194fcf2532fd73402 (patch) | |
| tree | 2da975668ffb4a36601eccb1b852a10dc9650bca | |
| parent | 9fe317ffd6e3545e7896389641b74c2977a5e4b4 (diff) | |
| download | mariadb-git-0697ee265fa4fe4d617dc96194fcf2532fd73402.tar.gz | |
MDEV-181: XID crash recovery across binlog boundaries
Keep track of how many pending XIDs (transactions that are prepared in
storage engine and written into binlog, but not yet durably committed
on disk in the engine) there are in each binlog.
When the count of one binlog drops to zero, write a new binlog checkpoint
event, telling which is the oldest binlog with pending XIDs.
When doing XA recovery after a crash, check the last binlog checkpoint
event, and scan all binlog files from that point onwards for XIDs that
must be committed if found in prepared state inside engine.
Remove the code in binlog rotation that waits for all prepared XIDs to
be committed before writing a new binlog file (this is no longer necessary
when recovery can scan multiple binlog files).
53 files changed, 1173 insertions, 220 deletions
diff --git a/mysql-test/extra/binlog_tests/mix_innodb_myisam_binlog.test b/mysql-test/extra/binlog_tests/mix_innodb_myisam_binlog.test index b41bfeaba74..4ce001cfdd7 100644 --- a/mysql-test/extra/binlog_tests/mix_innodb_myisam_binlog.test +++ b/mysql-test/extra/binlog_tests/mix_innodb_myisam_binlog.test @@ -318,8 +318,8 @@ connection con4; select get_lock("a",10); # wait for rollback to finish if (`select @@binlog_format = 'STATEMENT' || @@binlog_format = 'MIXED'`) { - --let $binlog_rollback= query_get_value(SHOW BINLOG EVENTS, Pos, 7) - --let $binlog_query= query_get_value(SHOW BINLOG EVENTS, Info, 7) + --let $binlog_rollback= query_get_value(SHOW BINLOG EVENTS, Pos, 8) + --let $binlog_query= query_get_value(SHOW BINLOG EVENTS, Info, 8) if ($binlog_query != ROLLBACK) { --echo Wrong query from SHOW BINLOG EVENTS. Expected ROLLBACK, got '$binlog_query' --source include/show_rpl_debug_info.inc diff --git a/mysql-test/extra/rpl_tests/create_recursive_construct.inc b/mysql-test/extra/rpl_tests/create_recursive_construct.inc index 6e130a8154f..e790a1db41f 100644 --- a/mysql-test/extra/rpl_tests/create_recursive_construct.inc +++ b/mysql-test/extra/rpl_tests/create_recursive_construct.inc @@ -325,7 +325,8 @@ if ($CRC_RET_stmt_sidef) { SHOW BINLOG EVENTS; --die Wrong number of warnings. } - --let $binlog_event= query_get_value(SHOW BINLOG EVENTS, Event_type, 2) + # There should be no events after format description and binlog checkpoint. + --let $binlog_event= query_get_value(SHOW BINLOG EVENTS, Event_type, 3) if ($binlog_event != No such row) { --enable_query_log --echo ******** Failure! Something was written to the binlog despite SQL_LOG_BIN=0 ******** @@ -345,23 +346,23 @@ if ($CRC_RET_stmt_sidef) { SHOW BINLOG EVENTS; --die Warnings printed } - --let $event_type= query_get_value(SHOW BINLOG EVENTS, Event_type, 3) - # The first event is format_description, the second is - # Query_event('BEGIN'), and the third should be our Query + --let $event_type= query_get_value(SHOW BINLOG EVENTS, Event_type, 4) + # The first event is format_description, the second is Binlog_checkpoint, + # the third Query_event('BEGIN'), and the fourth should be our Query # for 'INSERT DELAYED' unsafe_type 3, which is safe after # the fix of bug#54579. if (`SELECT $unsafe_type = 3 AND '$event_type' != 'Query'`) { --enable_query_log - --echo ******** Failure! Event number 3 was a '$event_type', not a 'Query'. ******** + --echo ******** Failure! Event number 4 was a '$event_type', not a 'Query'. ******** SHOW BINLOG EVENTS; --die Wrong events in binlog. } - # The first event is format_description, the second is - # Query_event('BEGIN'), and the third should be our Table_map + # The first event is format_description, the second is Binlog_checkpoint, + # the third is Query_event('BEGIN'), and the fourth should be our Table_map # for unsafe statement. if (`SELECT $unsafe_type != 3 AND '$event_type' != 'Table_map'`) { --enable_query_log - --echo ******** Failure! Event number 3 was a '$event_type', not a 'Table_map'. ******** + --echo ******** Failure! Event number 4 was a '$event_type', not a 'Table_map'. ******** SHOW BINLOG EVENTS; --die Wrong events in binlog. } diff --git a/mysql-test/extra/rpl_tests/rpl_deadlock.test b/mysql-test/extra/rpl_tests/rpl_deadlock.test index 0e862e041e6..56ff4683df8 100644 --- a/mysql-test/extra/rpl_tests/rpl_deadlock.test +++ b/mysql-test/extra/rpl_tests/rpl_deadlock.test @@ -34,7 +34,7 @@ INSERT INTO t3 VALUES (3); COMMIT; save_master_pos; # Save BEGIN event into variable -let $master_pos_begin= query_get_value(SHOW BINLOG EVENTS, Pos, 5); +let $master_pos_begin= query_get_value(SHOW BINLOG EVENTS, Pos, 6); --echo # 1) Test deadlock diff --git a/mysql-test/include/binlog_start_pos.inc b/mysql-test/include/binlog_start_pos.inc index add5a42a426..5237e357b28 100644 --- a/mysql-test/include/binlog_start_pos.inc +++ b/mysql-test/include/binlog_start_pos.inc @@ -15,14 +15,14 @@ # 1 /* Checksum algorithm */ + # 4 /* CRC32 length */ # -# With current number of events = 160, +# With current number of events = 161, # -# binlog_start_pos = 4 + 19 + 57 + 160 + 1 + 4 = 245. +# binlog_start_pos = 4 + 19 + 57 + 161 + 1 + 4 = 246. # ############################################################################## -let $binlog_start_pos=245; +let $binlog_start_pos=246; --disable_query_log -SET @binlog_start_pos=245; +SET @binlog_start_pos=246; --enable_query_log diff --git a/mysql-test/include/show_binlog_events.inc b/mysql-test/include/show_binlog_events.inc index e5670c054fa..5ab837f0e6b 100644 --- a/mysql-test/include/show_binlog_events.inc +++ b/mysql-test/include/show_binlog_events.inc @@ -9,7 +9,7 @@ # # It shows the first binary log file if $binlog_file is not given. # -# It shows events from the end position of the description event if +# It shows events from the end position of the binlog checkpoint event if # $binlog_start is not given. # # It shows all of the events if $binlog_limit is not given. diff --git a/mysql-test/include/show_binlog_events2.inc b/mysql-test/include/show_binlog_events2.inc index c32d12537fd..1fd9ce96d53 100644 --- a/mysql-test/include/show_binlog_events2.inc +++ b/mysql-test/include/show_binlog_events2.inc @@ -1,4 +1,4 @@ ---let $binlog_start=245 +--let $binlog_start=246 --replace_result $binlog_start <binlog_start> --replace_column 2 # 5 # --replace_regex /\/\* xid=.* \*\//\/* XID *\// /table_id: [0-9]+/table_id: #/ diff --git a/mysql-test/include/show_events.inc b/mysql-test/include/show_events.inc index ff5a7105c24..878773d2b5b 100644 --- a/mysql-test/include/show_events.inc +++ b/mysql-test/include/show_events.inc @@ -3,13 +3,28 @@ # It is only called by show_binlog_events.inc and show_relaylog_events.inc. ############################################################################## +# Do not modify $binlog_start - if we did, it could wrongly persist until a +# later call of show_events.inc. +if ($binlog_start) +{ + --let $_binlog_start= $binlog_start +} if (!$binlog_start) { - # If $binlog_start is not set, we will set it as the second event's - # position. The first event(Description Event) is always ignored. For - # description event's length might be changed because of adding new events, - # 'SHOW BINLOG EVENTS LIMIT 1' is used to get the right value. - --let $binlog_start= query_get_value(SHOW BINLOG EVENTS LIMIT 1, End_log_pos, 1) + # If $binlog_start is not set, we will set it as the third event's + # position (second in relay log which has not Binlog Checkpoing event). + # The first two events (Description Event and Binlog Checkpoint + # event) are always ignored. For description event's length might be changed + # because of adding new events, 'SHOW BINLOG EVENTS LIMIT 2' is used to get + # the right value. + if ($is_relay_log) + { + --let $_binlog_start= query_get_value(SHOW BINLOG EVENTS LIMIT 1, End_log_pos, 1) + } + if (!$is_relay_log) + { + --let $_binlog_start= query_get_value(SHOW BINLOG EVENTS LIMIT 2, End_log_pos, 2) + } } --let $_statement=show binlog events @@ -23,7 +38,7 @@ if ($binlog_file) --let $_statement= $_statement in '$binlog_file' } ---let $_statement= $_statement from $binlog_start +--let $_statement= $_statement from $_binlog_start # Cannot use if($binlog_limit) since the variable may begin with a 0 @@ -32,7 +47,7 @@ if (`SELECT '$binlog_limit' <> ''`) --let $_statement= $_statement limit $binlog_limit } ---replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR $binlog_start <binlog_start> +--replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR $_binlog_start <binlog_start> --replace_column 2 # 4 # 5 # --replace_regex /\/\* xid=.* \*\//\/* XID *\// /table_id: [0-9]+/table_id: #/ /file_id=[0-9]+/file_id=#/ /block_len=[0-9]+/block_len=#/ /Server ver:.*$/SERVER_VERSION, BINLOG_VERSION/ --eval $_statement diff --git a/mysql-test/r/mysqlbinlog_row.result b/mysql-test/r/mysqlbinlog_row.result index ce46b7ea898..6361cdadb32 100644 --- a/mysql-test/r/mysqlbinlog_row.result +++ b/mysql-test/r/mysqlbinlog_row.result @@ -335,6 +335,8 @@ DELIMITER /*!*/; #010909 4:46:40 server id 1 end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; # at # +#010909 4:46:40 server id 1 end_log_pos # Binlog checkpoint master-bin.000001 +# at # #010909 4:46:40 server id 1 end_log_pos # Query thread_id=# exec_time=# error_code=0 use `test`/*!*/; SET TIMESTAMP=1000000000/*!*/; diff --git a/mysql-test/r/mysqlbinlog_row_innodb.result b/mysql-test/r/mysqlbinlog_row_innodb.result index 63b64489a37..4be266d586c 100644 --- a/mysql-test/r/mysqlbinlog_row_innodb.result +++ b/mysql-test/r/mysqlbinlog_row_innodb.result @@ -2252,6 +2252,8 @@ DELIMITER /*!*/; #010909 4:46:40 server id 1 end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; # at # +#010909 4:46:40 server id 1 end_log_pos # Binlog checkpoint master-bin.000001 +# at # #010909 4:46:40 server id 1 end_log_pos # Query thread_id=# exec_time=# error_code=0 use `test`/*!*/; SET TIMESTAMP=1000000000/*!*/; @@ -3875,6 +3877,8 @@ DELIMITER /*!*/; #010909 4:46:40 server id 1 end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; # at # +#010909 4:46:40 server id 1 end_log_pos # Binlog checkpoint master-bin.000001 +# at # #010909 4:46:40 server id 1 end_log_pos # Query thread_id=# exec_time=# error_code=0 use `test`/*!*/; SET TIMESTAMP=1000000000/*!*/; @@ -4242,6 +4246,8 @@ DELIMITER /*!*/; #010909 4:46:40 server id 1 end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; # at # +#010909 4:46:40 server id 1 end_log_pos # Binlog checkpoint master-bin.000001 +# at # #010909 4:46:40 server id 1 end_log_pos # Query thread_id=# exec_time=# error_code=0 use `test`/*!*/; SET TIMESTAMP=1000000000/*!*/; @@ -4803,6 +4809,8 @@ DELIMITER /*!*/; #010909 4:46:40 server id 1 end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; # at # +#010909 4:46:40 server id 1 end_log_pos # Binlog checkpoint master-bin.000001 +# at # #010909 4:46:40 server id 1 end_log_pos # Query thread_id=# exec_time=# error_code=0 use `test`/*!*/; SET TIMESTAMP=1000000000/*!*/; diff --git a/mysql-test/r/mysqlbinlog_row_myisam.result b/mysql-test/r/mysqlbinlog_row_myisam.result index 6e8c7cd64f9..d4062565320 100644 --- a/mysql-test/r/mysqlbinlog_row_myisam.result +++ b/mysql-test/r/mysqlbinlog_row_myisam.result @@ -2252,6 +2252,8 @@ DELIMITER /*!*/; #010909 4:46:40 server id 1 end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; # at # +#010909 4:46:40 server id 1 end_log_pos # Binlog checkpoint master-bin.000001 +# at # #010909 4:46:40 server id 1 end_log_pos # Query thread_id=# exec_time=# error_code=0 use `test`/*!*/; SET TIMESTAMP=1000000000/*!*/; @@ -3897,6 +3899,8 @@ DELIMITER /*!*/; #010909 4:46:40 server id 1 end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; # at # +#010909 4:46:40 server id 1 end_log_pos # Binlog checkpoint master-bin.000001 +# at # #010909 4:46:40 server id 1 end_log_pos # Query thread_id=# exec_time=# error_code=0 use `test`/*!*/; SET TIMESTAMP=1000000000/*!*/; @@ -4270,6 +4274,8 @@ DELIMITER /*!*/; #010909 4:46:40 server id 1 end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; # at # +#010909 4:46:40 server id 1 end_log_pos # Binlog checkpoint master-bin.000001 +# at # #010909 4:46:40 server id 1 end_log_pos # Query thread_id=# exec_time=# error_code=0 use `test`/*!*/; SET TIMESTAMP=1000000000/*!*/; @@ -4841,6 +4847,8 @@ DELIMITER /*!*/; #010909 4:46:40 server id 1 end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; # at # +#010909 4:46:40 server id 1 end_log_pos # Binlog checkpoint master-bin.000001 +# at # #010909 4:46:40 server id 1 end_log_pos # Query thread_id=# exec_time=# error_code=0 use `test`/*!*/; SET TIMESTAMP=1000000000/*!*/; diff --git a/mysql-test/r/mysqlbinlog_row_trans.result b/mysql-test/r/mysqlbinlog_row_trans.result index 33c997d76a7..85106ab9684 100644 --- a/mysql-test/r/mysqlbinlog_row_trans.result +++ b/mysql-test/r/mysqlbinlog_row_trans.result @@ -131,6 +131,8 @@ DELIMITER /*!*/; #010909 4:46:40 server id 1 end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; # at # +#010909 4:46:40 server id 1 end_log_pos # Binlog checkpoint master-bin.000001 +# at # #010909 4:46:40 server id 1 end_log_pos # Query thread_id=# exec_time=# error_code=0 use `test`/*!*/; SET TIMESTAMP=1000000000/*!*/; diff --git a/mysql-test/r/mysqldump-max.result b/mysql-test/r/mysqldump-max.result index 6722f308358..fb0be20c119 100644 --- a/mysql-test/r/mysqldump-max.result +++ b/mysql-test/r/mysqldump-max.result @@ -332,12 +332,12 @@ a b 2 1 DROP TABLE t1; DROP TABLE t2; -SHOW BINLOG EVENTS LIMIT 6,3; +SHOW BINLOG EVENTS LIMIT 7,3; Log_name Pos Event_type Server_id End_log_pos Info -master-bin.000001 663 Query 1 731 BEGIN -master-bin.000001 731 Query 1 828 use `test`; INSERT INTO t2 VALUES (1,0), (2,0) -master-bin.000001 828 Xid 1 855 COMMIT /* XID */ --- CHANGE MASTER TO MASTER_LOG_FILE='master-bin.000001', MASTER_LOG_POS=855; +master-bin.000001 704 Query 1 772 BEGIN +master-bin.000001 772 Query 1 869 use `test`; INSERT INTO t2 VALUES (1,0), (2,0) +master-bin.000001 869 Xid 1 896 COMMIT /* XID */ +-- CHANGE MASTER TO MASTER_LOG_FILE='master-bin.000001', MASTER_LOG_POS=896; SELECT * FROM t1 ORDER BY a; a 1 diff --git a/mysql-test/r/xa_binlog.result b/mysql-test/r/xa_binlog.result index 3ce64953902..395f0dc62a4 100644 --- a/mysql-test/r/xa_binlog.result +++ b/mysql-test/r/xa_binlog.result @@ -18,7 +18,7 @@ a 1 2 3 -SHOW BINLOG EVENTS LIMIT 1,9; +SHOW BINLOG EVENTS LIMIT 2,9; Log_name Pos Event_type Server_id End_log_pos Info master-bin.000001 # Query 1 # BEGIN master-bin.000001 # Query 1 # use `test`; INSERT INTO t1 VALUES (1) diff --git a/mysql-test/suite/binlog/r/binlog_ioerr.result b/mysql-test/suite/binlog/r/binlog_ioerr.result index f8e2d189f57..68ff5264aa3 100644 --- a/mysql-test/suite/binlog/r/binlog_ioerr.result +++ b/mysql-test/suite/binlog/r/binlog_ioerr.result @@ -16,6 +16,7 @@ a SHOW BINLOG EVENTS; Log_name Pos Event_type Server_id End_log_pos Info BINLOG POS Format_desc 1 ENDPOS Server ver: #, Binlog ver: # +BINLOG POS Binlog_checkpoint 1 ENDPOS master-bin.000001 BINLOG POS Query 1 ENDPOS use `test`; CREATE TABLE t1 (a INT PRIMARY KEY) ENGINE=innodb BINLOG POS Query 1 ENDPOS BEGIN BINLOG POS Query 1 ENDPOS use `test`; INSERT INTO t1 VALUES(0) diff --git a/mysql-test/suite/binlog/r/binlog_row_annotate.result b/mysql-test/suite/binlog/r/binlog_row_annotate.result index 0c008661784..58cac276c95 100644 --- a/mysql-test/suite/binlog/r/binlog_row_annotate.result +++ b/mysql-test/suite/binlog/r/binlog_row_annotate.result @@ -8,6 +8,7 @@ ##################################################################################### show binlog events in 'master-bin.000001' from <start_pos>; Log_name Pos Event_type Server_id End_log_pos Info +master-bin.000001 # Binlog_checkpoint 1 # master-bin.000001 master-bin.000001 # Query 1 # DROP DATABASE IF EXISTS test1 master-bin.000001 # Query 1 # DROP DATABASE IF EXISTS test2 master-bin.000001 # Query 1 # DROP DATABASE IF EXISTS test3 @@ -67,6 +68,8 @@ DELIMITER /*!*/; #010909 4:46:40 server id # end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; # at # +#010909 4:46:40 server id # end_log_pos # Binlog checkpoint master-bin.000001 +# at # #010909 4:46:40 server id # end_log_pos # Query thread_id=# exec_time=# error_code=0 SET TIMESTAMP=1000000000/*!*/; SET @@session.pseudo_thread_id=#/*!*/; @@ -293,6 +296,8 @@ DELIMITER /*!*/; #010909 4:46:40 server id # end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; # at # +#010909 4:46:40 server id # end_log_pos # Binlog checkpoint master-bin.000001 +# at # #010909 4:46:40 server id # end_log_pos # Query thread_id=# exec_time=# error_code=0 SET TIMESTAMP=1000000000/*!*/; SET @@session.pseudo_thread_id=#/*!*/; @@ -437,6 +442,8 @@ DELIMITER /*!*/; #010909 4:46:40 server id # end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; # at # +#010909 4:46:40 server id # end_log_pos # Binlog checkpoint master-bin.000001 +# at # #010909 4:46:40 server id # end_log_pos # Query thread_id=# exec_time=# error_code=0 SET TIMESTAMP=1000000000/*!*/; SET @@session.pseudo_thread_id=#/*!*/; @@ -653,6 +660,8 @@ DELIMITER /*!*/; #010909 4:46:40 server id # end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; # at # +#010909 4:46:40 server id # end_log_pos # Binlog checkpoint master-bin.000001 +# at # #010909 4:46:40 server id # end_log_pos # Query thread_id=# exec_time=# error_code=0 SET TIMESTAMP=1000000000/*!*/; SET @@session.pseudo_thread_id=#/*!*/; @@ -879,6 +888,8 @@ DELIMITER /*!*/; #010909 4:46:40 server id # end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; # at # +#010909 4:46:40 server id # end_log_pos # Binlog checkpoint master-bin.000001 +# at # #010909 4:46:40 server id # end_log_pos # Query thread_id=# exec_time=# error_code=0 SET TIMESTAMP=1000000000/*!*/; SET @@session.pseudo_thread_id=#/*!*/; @@ -1023,6 +1034,8 @@ DELIMITER /*!*/; #010909 4:46:40 server id # end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; # at # +#010909 4:46:40 server id # end_log_pos # Binlog checkpoint master-bin.000001 +# at # #010909 4:46:40 server id # end_log_pos # Query thread_id=# exec_time=# error_code=0 SET TIMESTAMP=1000000000/*!*/; SET @@session.pseudo_thread_id=#/*!*/; diff --git a/mysql-test/suite/binlog/r/binlog_row_binlog.result b/mysql-test/suite/binlog/r/binlog_row_binlog.result index 95477d13b50..26710178cd8 100644 --- a/mysql-test/suite/binlog/r/binlog_row_binlog.result +++ b/mysql-test/suite/binlog/r/binlog_row_binlog.result @@ -728,6 +728,7 @@ BINLOG ' SHOW BINLOG EVENTS; Log_name Pos Event_type Server_id End_log_pos Info # # Format_desc 1 # Server ver: #, Binlog ver: # +# # Binlog_checkpoint 1 # master-bin.000001 # # Query 1 # use `test`; CREATE TABLE t1 (a INT PRIMARY KEY) # # Query 1 # BEGIN # # Table_map 1 # table_id: # (test.t1) diff --git a/mysql-test/suite/binlog/r/binlog_row_mysqlbinlog_options.result b/mysql-test/suite/binlog/r/binlog_row_mysqlbinlog_options.result index 9c780390ca8..ae732ffcc08 100644 --- a/mysql-test/suite/binlog/r/binlog_row_mysqlbinlog_options.result +++ b/mysql-test/suite/binlog/r/binlog_row_mysqlbinlog_options.result @@ -34,6 +34,8 @@ DELIMITER /*!*/; # at # #010909 4:46:40 server id # end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; +#010909 4:46:40 server id # end_log_pos # Binlog checkpoint master-bin.000001 +# at # # at # use `new_test1`/*!*/; #010909 4:46:40 server id # end_log_pos # Query thread_id=# exec_time=# error_code=0 @@ -228,6 +230,8 @@ DELIMITER /*!*/; # at # #010909 4:46:40 server id # end_log_pos # Start: binlog v 4, server v #.##.## created 010909 4:46:40 at startup ROLLBACK/*!*/; +#010909 4:46:40 server id # end_log_pos # Binlog checkpoint master-bin.000001 +# at # # at # use `new_test1`/*!*/; #010909 4:46:40 server id # end_log_pos # Query thread_id=# exec_time=# error_code=0 diff --git a/mysql-test/suite/binlog/r/binlog_server_id.result b/mysql-test/suite/binlog/r/binlog_server_id.result index f7d778a288b..991fd6e476b 100644 --- a/mysql-test/suite/binlog/r/binlog_server_id.result +++ b/mysql-test/suite/binlog/r/binlog_server_id.result @@ -7,6 +7,7 @@ select @@server_id; 1 show binlog events from <binlog_start>; Log_name Pos Event_type Server_id End_log_pos Info +master-bin.000001 # Binlog_checkpoint 1 # master-bin.000001 master-bin.000001 # Query 1 # use `test`; DROP TABLE IF EXISTS `t1`,`t2`,`t3` /* generated by server */ master-bin.000001 # Query 1 # use `test`; create table t1 (a int) set global server_id=2; @@ -16,6 +17,7 @@ select @@server_id; 2 show binlog events from <binlog_start>; Log_name Pos Event_type Server_id End_log_pos Info +master-bin.000001 # Binlog_checkpoint 1 # master-bin.000001 master-bin.000001 # Query 1 # use `test`; DROP TABLE IF EXISTS `t1`,`t2`,`t3` /* generated by server */ master-bin.000001 # Query 1 # use `test`; create table t1 (a int) master-bin.000001 # Query 2 # use `test`; create table t2 (b int) @@ -26,6 +28,7 @@ select @@server_id; 3 show binlog events from <binlog_start>; Log_name Pos Event_type Server_id End_log_pos Info +master-bin.000001 # Binlog_checkpoint 1 # master-bin.000001 master-bin.000001 # Query 1 # use `test`; DROP TABLE IF EXISTS `t1`,`t2`,`t3` /* generated by server */ master-bin.000001 # Query 1 # use `test`; create table t1 (a int) master-bin.000001 # Query 2 # use `test`; create table t2 (b int) diff --git a/mysql-test/suite/binlog/r/binlog_stm_binlog.result b/mysql-test/suite/binlog/r/binlog_stm_binlog.result index 062f4f4e906..f9d9fa1d18d 100644 --- a/mysql-test/suite/binlog/r/binlog_stm_binlog.result +++ b/mysql-test/suite/binlog/r/binlog_stm_binlog.result @@ -521,6 +521,7 @@ BINLOG ' SHOW BINLOG EVENTS; Log_name Pos Event_type Server_id End_log_pos Info # # Format_desc 1 # Server ver: #, Binlog ver: # +# # Binlog_checkpoint 1 # master-bin.000001 # # Query 1 # use `test`; CREATE TABLE t1 (a INT PRIMARY KEY) # # Query 1 # BEGIN # # Query 1 # use `test`; INSERT INTO t1 VALUES (1) diff --git a/mysql-test/suite/binlog/r/binlog_stm_blackhole.result b/mysql-test/suite/binlog/r/binlog_stm_blackhole.result index e76f6b494f9..2b5bd76a338 100644 --- a/mysql-test/suite/binlog/r/binlog_stm_blackhole.result +++ b/mysql-test/suite/binlog/r/binlog_stm_blackhole.result @@ -175,6 +175,7 @@ set insert_id= 5; insert into t1 values (55), (NULL); show binlog events from <binlog_start>; Log_name Pos Event_type Server_id End_log_pos Info +master-bin.000001 # Binlog_checkpoint 1 # master-bin.000001 master-bin.000001 # Query 1 # use `test`; create table t1 (a int auto_increment, primary key (a)) engine=blackhole master-bin.000001 # Query 1 # BEGIN master-bin.000001 # Intvar 1 # INSERT_ID=1 diff --git a/mysql-test/suite/binlog/r/binlog_xa_recover.result b/mysql-test/suite/binlog/r/binlog_xa_recover.result new file mode 100644 index 00000000000..41df149a928 --- /dev/null +++ b/mysql-test/suite/binlog/r/binlog_xa_recover.result @@ -0,0 +1,175 @@ +SET GLOBAL max_binlog_size= 4096; +CREATE TABLE t1 (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=Innodb; +CREATE TABLE t2 (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=Myisam; +SET @@global.debug_dbug='+d,skip_commit_ordered'; +INSERT INTO t1 VALUES (0, REPEAT("x", 4100)); +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con1_ready WAIT_FOR _ever"; +INSERT INTO t1 VALUES (1, REPEAT("x", 4100)); +SET DEBUG_SYNC= "now WAIT_FOR con1_ready"; +INSERT INTO t2 VALUES (1, "force binlog rotation"); +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con2_ready WAIT_FOR _ever"; +INSERT INTO t1 VALUES (2, NULL); +SET DEBUG_SYNC= "now WAIT_FOR con2_ready"; +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con3_ready WAIT_FOR _ever"; +INSERT INTO t1 VALUES (3, REPEAT("x", 4100)); +SET DEBUG_SYNC= "now WAIT_FOR con3_ready"; +INSERT INTO t2 VALUES (2, "force binlog rotation"); +FLUSH TABLES t2; +show binary logs; +Log_name File_size +master-bin.000001 # +master-bin.000002 # +master-bin.000003 # +master-bin.000004 # +show binlog events in 'master-bin.000001' from <binlog_start>; +Log_name Pos Event_type Server_id End_log_pos Info +master-bin.000001 # Format_desc # # SERVER_VERSION, BINLOG_VERSION +master-bin.000001 # Binlog_checkpoint # # master-bin.000001 +master-bin.000001 # Query # # use `test`; CREATE TABLE t1 (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=Innodb +master-bin.000001 # Query # # use `test`; CREATE TABLE t2 (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=Myisam +master-bin.000001 # Query # # BEGIN +master-bin.000001 # Table_map # # table_id: # (test.t1) +master-bin.000001 # Write_rows # # table_id: # flags: STMT_END_F +master-bin.000001 # Xid # # COMMIT /* XID */ +master-bin.000001 # Rotate # # master-bin.000002;pos=<binlog_start> +show binlog events in 'master-bin.000002' from <binlog_start>; +Log_name Pos Event_type Server_id End_log_pos Info +master-bin.000002 # Format_desc # # SERVER_VERSION, BINLOG_VERSION +master-bin.000002 # Binlog_checkpoint # # master-bin.000002 +master-bin.000002 # Query # # BEGIN +master-bin.000002 # Table_map # # table_id: # (test.t1) +master-bin.000002 # Write_rows # # table_id: # flags: STMT_END_F +master-bin.000002 # Xid # # COMMIT /* XID */ +master-bin.000002 # Query # # BEGIN +master-bin.000002 # Table_map # # table_id: # (test.t2) +master-bin.000002 # Write_rows # # table_id: # flags: STMT_END_F +master-bin.000002 # Query # # COMMIT +master-bin.000002 # Rotate # # master-bin.000003;pos=<binlog_start> +show binlog events in 'master-bin.000003' from <binlog_start>; +Log_name Pos Event_type Server_id End_log_pos Info +master-bin.000003 # Format_desc # # SERVER_VERSION, BINLOG_VERSION +master-bin.000003 # Binlog_checkpoint # # master-bin.000002 +master-bin.000003 # Query # # BEGIN +master-bin.000003 # Table_map # # table_id: # (test.t1) +master-bin.000003 # Write_rows # # table_id: # flags: STMT_END_F +master-bin.000003 # Xid # # COMMIT /* XID */ +master-bin.000003 # Query # # BEGIN +master-bin.000003 # Table_map # # table_id: # (test.t1) +master-bin.000003 # Write_rows # # table_id: # flags: STMT_END_F +master-bin.000003 # Xid # # COMMIT /* XID */ +master-bin.000003 # Query # # BEGIN +master-bin.000003 # Table_map # # table_id: # (test.t2) +master-bin.000003 # Write_rows # # table_id: # flags: STMT_END_F +master-bin.000003 # Query # # COMMIT +master-bin.000003 # Rotate # # master-bin.00000<binlog_start>;pos=<binlog_start> +show binlog events in 'master-bin.00000<binlog_start>' from <binlog_start>; +Log_name Pos Event_type Server_id End_log_pos Info +master-bin.00000<binlog_start> # Format_desc # # SERVER_VERSION, BINLOG_VERSION +master-bin.00000<binlog_start> # Binlog_checkpoint # # master-bin.000002 +master-bin.00000<binlog_start> # Query # # use `test`; FLUSH TABLES t2 +We should see only one entry here, a=0: +SELECT a FROM t1 ORDER BY a; +a +0 +PURGE BINARY LOGS TO "master-bin.000004"; +show binary logs; +Log_name File_size +master-bin.000002 # +master-bin.000003 # +master-bin.000004 # +SET SESSION debug_dbug="+d,crash_commit_after_log"; +INSERT INTO t1 VALUES (4, NULL); +Got one of the listed errors +SELECT a FROM t1 ORDER BY a; +a +0 +1 +2 +3 +4 +*** Test that RESET MASTER waits for pending XIDs to be unlogged. +SET @old_max_binlog_size= @@global.max_binlog_size; +SET GLOBAL max_binlog_size= 4096; +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con10_ready WAIT_FOR con10_go"; +INSERT INTO t1 VALUES (10, NULL); +SET DEBUG_SYNC= "now WAIT_FOR con10_ready"; +INSERT INTO t2 VALUES (10, REPEAT("x", 4100)); +INSERT INTO t2 VALUES (11, REPEAT("x", 4100)); +show binary logs; +Log_name File_size +master-bin.000002 # +master-bin.000003 # +master-bin.000004 # +master-bin.000005 # +master-bin.000006 # +master-bin.000007 # +SET DEBUG_SYNC= "execute_command_after_close_tables SIGNAL reset_master_done"; +RESET MASTER; +This will timeout, as RESET MASTER is blocked +SET DEBUG_SYNC= "now WAIT_FOR reset_master_done TIMEOUT 1"; +Warnings: +Warning 1639 debug sync point wait timed out +SET DEBUG_SYNC= "now SIGNAL con10_go"; +show binary logs; +Log_name File_size +master-bin.000001 # +*** Test that binlog N is active, and last pending trx in (N-1) is +unlogged while there is still a pending trx in (N-2). +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con10_ready WAIT_FOR con10_continue"; +INSERT INTO t1 VALUES (20, REPEAT("x", 4100)); +SET DEBUG_SYNC= "now WAIT_FOR con10_ready"; +INSERT INTO t2 VALUES (3, "force binlog rotation"); +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con11_ready WAIT_FOR con11_continue"; +INSERT INTO t1 VALUES (21, REPEAT("x", 4100)); +SET DEBUG_SYNC= "now WAIT_FOR con11_ready"; +INSERT INTO t2 VALUES (4, "force binlog rotation"); +show binary logs; +Log_name File_size +master-bin.000001 # +master-bin.000002 # +master-bin.000003 # +show binlog events in 'master-bin.000001' from <binlog_start>; +Log_name Pos Event_type Server_id End_log_pos Info +master-bin.000001 # Format_desc # # SERVER_VERSION, BINLOG_VERSION +master-bin.000001 # Binlog_checkpoint # # master-bin.000001 +master-bin.000001 # Query # # BEGIN +master-bin.000001 # Table_map # # table_id: # (test.t1) +master-bin.000001 # Write_rows # # table_id: # flags: STMT_END_F +master-bin.000001 # Xid # # COMMIT /* XID */ +master-bin.000001 # Query # # BEGIN +master-bin.000001 # Table_map # # table_id: # (test.t2) +master-bin.000001 # Write_rows # # table_id: # flags: STMT_END_F +master-bin.000001 # Query # # COMMIT +master-bin.000001 # Rotate # # master-bin.000002;pos=<binlog_start> +show binlog events in 'master-bin.000002' from <binlog_start>; +Log_name Pos Event_type Server_id End_log_pos Info +master-bin.000002 # Format_desc # # SERVER_VERSION, BINLOG_VERSION +master-bin.000002 # Binlog_checkpoint # # master-bin.000001 +master-bin.000002 # Query # # BEGIN +master-bin.000002 # Table_map # # table_id: # (test.t1) +master-bin.000002 # Write_rows # # table_id: # flags: STMT_END_F +master-bin.000002 # Xid # # COMMIT /* XID */ +master-bin.000002 # Query # # BEGIN +master-bin.000002 # Table_map # # table_id: # (test.t2) +master-bin.000002 # Write_rows # # table_id: # flags: STMT_END_F +master-bin.000002 # Query # # COMMIT +master-bin.000002 # Rotate # # master-bin.000003;pos=<binlog_start> +show binlog events in 'master-bin.000003' from <binlog_start>; +Log_name Pos Event_type Server_id End_log_pos Info +master-bin.000003 # Format_desc # # SERVER_VERSION, BINLOG_VERSION +master-bin.000003 # Binlog_checkpoint # # master-bin.000001 +SET DEBUG_SYNC= "now SIGNAL con11_continue"; +con10 is still pending, no new binlog checkpoint should have been logged. +show binlog events in 'master-bin.000003' from <binlog_start>; +Log_name Pos Event_type Server_id End_log_pos Info +master-bin.000003 # Format_desc # # SERVER_VERSION, BINLOG_VERSION +master-bin.000003 # Binlog_checkpoint # # master-bin.000001 +SET DEBUG_SYNC= "now SIGNAL con10_continue"; +No XIDs are pending, a new binlog checkpoint should have been logged. +show binlog events in 'master-bin.000003' from <binlog_start>; +Log_name Pos Event_type Server_id End_log_pos Info +master-bin.000003 # Format_desc # # SERVER_VERSION, BINLOG_VERSION +master-bin.000003 # Binlog_checkpoint # # master-bin.000001 +master-bin.000003 # Binlog_checkpoint # # master-bin.000003 +DROP TABLE t1, t2; +SET GLOBAL max_binlog_size= @old_max_binlog_size; diff --git a/mysql-test/suite/binlog/t/binlog_killed.test b/mysql-test/suite/binlog/t/binlog_killed.test index 9b6420df4b4..ff558ee2948 100644 --- a/mysql-test/suite/binlog/t/binlog_killed.test +++ b/mysql-test/suite/binlog/t/binlog_killed.test @@ -59,8 +59,8 @@ reap; let $rows= `select count(*) from t2 /* must be 2 or 0 */`; let $MYSQLD_DATADIR= `select @@datadir`; ---let $binlog_killed_pos=query_get_value(SHOW BINLOG EVENTS, Pos, 4) ---let $binlog_killed_end_log_pos=query_get_value(SHOW BINLOG EVENTS, End_log_pos, 4) +--let $binlog_killed_pos=query_get_value(SHOW BINLOG EVENTS, Pos, 5) +--let $binlog_killed_end_log_pos=query_get_value(SHOW BINLOG EVENTS, End_log_pos, 5) --exec $MYSQL_BINLOG --force-if-open --start-position=$binlog_killed_pos --stop-position=$binlog_killed_end_log_pos $MYSQLD_DATADIR/master-bin.000001 > $MYSQLTEST_VARDIR/tmp/kill_query_calling_sp.binlog --replace_result $MYSQLTEST_VARDIR MYSQLTEST_VARDIR --disable_result_log @@ -270,8 +270,8 @@ select * from t4 order by b /* must be (1,1), (1,2) */; select @b /* must be 1 at the end of a stmt calling bug27563() */; --echo must have the update query event on the 4th line source include/show_binlog_events.inc; ---let $binlog_killed_pos= query_get_value(SHOW BINLOG EVENTS, Pos, 4) ---let $binlog_killed_end_log_pos= query_get_value(SHOW BINLOG EVENTS, End_log_pos, 4) +--let $binlog_killed_pos= query_get_value(SHOW BINLOG EVENTS, Pos, 5) +--let $binlog_killed_end_log_pos= query_get_value(SHOW BINLOG EVENTS, End_log_pos, 5) --echo *** a proof the query is binlogged with an error *** @@ -318,8 +318,8 @@ select count(*) from t4 /* must be 1 */; select @b /* must be 1 at the end of a stmt calling bug27563() */; --echo must have the delete query event on the 4th line source include/show_binlog_events.inc; ---let $binlog_killed_pos= query_get_value(SHOW BINLOG EVENTS, Pos, 4) ---let $binlog_killed_end_log_pos= query_get_value(SHOW BINLOG EVENTS, End_log_pos, 4) +--let $binlog_killed_pos= query_get_value(SHOW BINLOG EVENTS, Pos, 5) +--let $binlog_killed_end_log_pos= query_get_value(SHOW BINLOG EVENTS, End_log_pos, 5) # a proof the query is binlogged with an error diff --git a/mysql-test/suite/binlog/t/binlog_killed_simulate.test b/mysql-test/suite/binlog/t/binlog_killed_simulate.test index ba111fd0145..33037710379 100644 --- a/mysql-test/suite/binlog/t/binlog_killed_simulate.test +++ b/mysql-test/suite/binlog/t/binlog_killed_simulate.test @@ -50,8 +50,8 @@ load data infile '../../std_data/rpl_loaddata.dat' into table t2 /* will be "kil # a proof the query is binlogged with an error ---let $binlog_load_data= query_get_value(SHOW BINLOG EVENTS, Pos, 3) ---let $binlog_end= query_get_value(SHOW BINLOG EVENTS, Pos, 4) +--let $binlog_load_data= query_get_value(SHOW BINLOG EVENTS, Pos, 4) +--let $binlog_end= query_get_value(SHOW BINLOG EVENTS, Pos, 5) source include/show_binlog_events.inc; --exec $MYSQL_BINLOG --force-if-open --start-position=$binlog_load_data --stop-position=$binlog_end $MYSQLD_DATADIR/master-bin.000001 > $MYSQLTEST_VARDIR/tmp/binlog_killed_bug27571.binlog diff --git a/mysql-test/suite/binlog/t/binlog_xa_recover-master.opt b/mysql-test/suite/binlog/t/binlog_xa_recover-master.opt new file mode 100644 index 00000000000..425fda95086 --- /dev/null +++ b/mysql-test/suite/binlog/t/binlog_xa_recover-master.opt @@ -0,0 +1 @@ +--skip-stack-trace --skip-core-file diff --git a/mysql-test/suite/binlog/t/binlog_xa_recover.test b/mysql-test/suite/binlog/t/binlog_xa_recover.test new file mode 100644 index 00000000000..7a4cc17112e --- /dev/null +++ b/mysql-test/suite/binlog/t/binlog_xa_recover.test @@ -0,0 +1,174 @@ +--source include/have_innodb.inc +--source include/have_debug.inc +--source include/have_debug_sync.inc +--source include/have_binlog_format_row.inc +# Valgrind does not work well with test that crashes the server +--source include/not_valgrind.inc + +SET GLOBAL max_binlog_size= 4096; + +CREATE TABLE t1 (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=Innodb; +CREATE TABLE t2 (a INT PRIMARY KEY, b MEDIUMTEXT) ENGINE=Myisam; + +# Transactions are not guaranteed stored durably on disk in the engine until +# they are fsync()ed, which normally happens during commit(). But there is no +# guarantee that they will _not_ be durable, in particular loosing results +# of a write(2) system call normally requires a kernel crash (as opposed to +# just mysqld crash), which is inconvenient to do in a test suite. +# So instead we do an error insert to prevent commit_ordered() from being +# called in the engine - so nothing will be written to disk at all, and crash +# recovery is sure to be needed. +SET @@global.debug_dbug='+d,skip_commit_ordered'; + +INSERT INTO t1 VALUES (0, REPEAT("x", 4100)); + +# Now start a bunch of transactions that span multiple binlog +# files. Leave then in the state prepared-but-not-committed in the engine +# and crash the server. Check that crash recovery is able to recover all +# of them. + +connect(con1,localhost,root,,); +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con1_ready WAIT_FOR _ever"; +send INSERT INTO t1 VALUES (1, REPEAT("x", 4100)); + +connection default; +SET DEBUG_SYNC= "now WAIT_FOR con1_ready"; +INSERT INTO t2 VALUES (1, "force binlog rotation"); + +connect(con2,localhost,root,,); +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con2_ready WAIT_FOR _ever"; +send INSERT INTO t1 VALUES (2, NULL); + +connection default; +SET DEBUG_SYNC= "now WAIT_FOR con2_ready"; + +connect(con3,localhost,root,,); +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con3_ready WAIT_FOR _ever"; +send INSERT INTO t1 VALUES (3, REPEAT("x", 4100)); +connection default; +SET DEBUG_SYNC= "now WAIT_FOR con3_ready"; +INSERT INTO t2 VALUES (2, "force binlog rotation"); +# So we won't get warnings about t2 being crashed. +FLUSH TABLES t2; + +# Check that everything is committed in binary log. +--source include/show_binary_logs.inc +--let $binlog_file= master-bin.000001 +--let $binlog_start= 4 +--source include/show_binlog_events.inc +--let $binlog_file= master-bin.000002 +--source include/show_binlog_events.inc +--let $binlog_file= master-bin.000003 +--source include/show_binlog_events.inc +--let $binlog_file= master-bin.000004 +--source include/show_binlog_events.inc + +# Check that transactions really are not yet committed in engine. +# (This works because of debug_dbug='+d,skip_commit_ordered'). +--echo We should see only one entry here, a=0: +SELECT a FROM t1 ORDER BY a; + + +# Check that server will not purge too much. +PURGE BINARY LOGS TO "master-bin.000004"; +--source include/show_binary_logs.inc + +# Now crash the server with one more transaction in prepared state. +system echo wait-binlog_xa_recover.test >> $MYSQLTEST_VARDIR/tmp/mysqld.1.expect; +SET SESSION debug_dbug="+d,crash_commit_after_log"; +--error 2006,2013 +INSERT INTO t1 VALUES (4, NULL); + +system echo restart-group_commit_binlog_pos.test >> $MYSQLTEST_VARDIR/tmp/mysqld.1.expect; + +connection default; +--enable_reconnect +--source include/wait_until_connected_again.inc + +# Check that all transactions are recovered. +SELECT a FROM t1 ORDER BY a; + + +--echo *** Test that RESET MASTER waits for pending XIDs to be unlogged. + +SET @old_max_binlog_size= @@global.max_binlog_size; +SET GLOBAL max_binlog_size= 4096; +# con10 will hang with a pending XID, blocking RESET MASTER. +connect(con10,localhost,root,,); +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con10_ready WAIT_FOR con10_go"; +send INSERT INTO t1 VALUES (10, NULL); + +connection default; +SET DEBUG_SYNC= "now WAIT_FOR con10_ready"; +# Let's add a few binlog rotations just for good measure. +INSERT INTO t2 VALUES (10, REPEAT("x", 4100)); +INSERT INTO t2 VALUES (11, REPEAT("x", 4100)); +--source include/show_binary_logs.inc +SET DEBUG_SYNC= "execute_command_after_close_tables SIGNAL reset_master_done"; +send RESET MASTER; + +connect(con11,localhost,root,,); +--echo This will timeout, as RESET MASTER is blocked +SET DEBUG_SYNC= "now WAIT_FOR reset_master_done TIMEOUT 1"; +# Wake up transaction to allow RESET MASTER to complete. +SET DEBUG_SYNC= "now SIGNAL con10_go"; + +connection con10; +reap; + +connection default; +reap; +--source include/show_binary_logs.inc + + +--echo *** Test that binlog N is active, and last pending trx in (N-1) is +--echo unlogged while there is still a pending trx in (N-2). + +connection con10; +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con10_ready WAIT_FOR con10_continue"; +send INSERT INTO t1 VALUES (20, REPEAT("x", 4100)); + +connection default; +SET DEBUG_SYNC= "now WAIT_FOR con10_ready"; +INSERT INTO t2 VALUES (3, "force binlog rotation"); + +connection con11; +SET DEBUG_SYNC= "ha_commit_trans_after_log_and_order SIGNAL con11_ready WAIT_FOR con11_continue"; +send INSERT INTO t1 VALUES (21, REPEAT("x", 4100)); + +connection default; +SET DEBUG_SYNC= "now WAIT_FOR con11_ready"; +INSERT INTO t2 VALUES (4, "force binlog rotation"); +--source include/show_binary_logs.inc +--let $binlog_file= master-bin.000001 +--source include/show_binlog_events.inc +--let $binlog_file= master-bin.000002 +--source include/show_binlog_events.inc +--let $binlog_file= master-bin.000003 +--source include/show_binlog_events.inc + +SET DEBUG_SYNC= "now SIGNAL con11_continue"; + +connection con11; +reap; + +connection default; +--echo con10 is still pending, no new binlog checkpoint should have been logged. +--let $binlog_file= master-bin.000003 +--source include/show_binlog_events.inc + +SET DEBUG_SYNC= "now SIGNAL con10_continue"; + +connection con10; +reap; + +connection default; +--echo No XIDs are pending, a new binlog checkpoint should have been logged. +--let $binlog_file= master-bin.000003 +--source include/show_binlog_events.inc + + +# Cleanup +connection default; +DROP TABLE t1, t2; +SET GLOBAL max_binlog_size= @old_max_binlog_size; diff --git a/mysql-test/suite/innodb/r/binlog_consistent.result b/mysql-test/suite/innodb/r/binlog_consistent.result index 2e523c40a5b..68838e8d52b 100644 --- a/mysql-test/suite/innodb/r/binlog_consistent.result +++ b/mysql-test/suite/innodb/r/binlog_consistent.result @@ -3,11 +3,11 @@ RESET MASTER; CREATE TABLE t1 (a INT, b VARCHAR(100), PRIMARY KEY (a,b)) ENGINE=innodb; SHOW MASTER STATUS; File Position Binlog_Do_DB Binlog_Ignore_DB -master-bin.000001 380 +master-bin.000001 421 SHOW STATUS LIKE 'binlog_snapshot_%'; Variable_name Value binlog_snapshot_file master-bin.000001 -binlog_snapshot_position 380 +binlog_snapshot_position 421 BEGIN; INSERT INTO t1 VALUES (0, ""); # Connection con1 @@ -38,10 +38,10 @@ a b SHOW STATUS LIKE 'binlog_snapshot_%'; Variable_name Value binlog_snapshot_file master-bin.000001 -binlog_snapshot_position 904 +binlog_snapshot_position 945 SHOW MASTER STATUS; File Position Binlog_Do_DB Binlog_Ignore_DB -master-bin.000001 1316 +master-bin.000001 1357 SELECT * FROM t2 ORDER BY a; a 2 @@ -60,44 +60,45 @@ a b SHOW STATUS LIKE 'binlog_snapshot_%'; Variable_name Value binlog_snapshot_file master-bin.000001 -binlog_snapshot_position 904 +binlog_snapshot_position 945 SHOW MASTER STATUS; File Position Binlog_Do_DB Binlog_Ignore_DB -master-bin.000002 245 +master-bin.000002 286 COMMIT; SHOW STATUS LIKE 'binlog_snapshot_%'; Variable_name Value binlog_snapshot_file master-bin.000002 -binlog_snapshot_position 245 +binlog_snapshot_position 286 SHOW MASTER STATUS; File Position Binlog_Do_DB Binlog_Ignore_DB -master-bin.000002 245 +master-bin.000002 286 SHOW BINLOG EVENTS; Log_name Pos Event_type Server_id End_log_pos Info -master-bin.000001 4 Format_desc 1 245 Server ver: #, Binlog ver: # -master-bin.000001 245 Query 1 380 use `test`; CREATE TABLE t1 (a INT, b VARCHAR(100), PRIMARY KEY (a,b)) ENGINE=innodb -master-bin.000001 380 Query 1 492 use `test`; CREATE TABLE t2 (a INT PRIMARY KEY) ENGINE=myisam -master-bin.000001 492 Query 1 560 BEGIN -master-bin.000001 560 Query 1 648 use `test`; INSERT INTO t2 VALUES (2) -master-bin.000001 648 Query 1 717 COMMIT -master-bin.000001 717 Query 1 785 BEGIN -master-bin.000001 785 Query 1 877 use `test`; INSERT INTO t1 VALUES (0, "") -master-bin.000001 877 Xid 1 904 COMMIT /* XID */ -master-bin.000001 904 Query 1 972 BEGIN -master-bin.000001 972 Query 1 1060 use `test`; INSERT INTO t2 VALUES (3) -master-bin.000001 1060 Query 1 1129 COMMIT -master-bin.000001 1129 Query 1 1197 BEGIN -master-bin.000001 1197 Query 1 1289 use `test`; INSERT INTO t1 VALUES (4, "") -master-bin.000001 1289 Xid 1 1316 COMMIT /* XID */ -master-bin.000001 1316 Query 1 1384 BEGIN -master-bin.000001 1384 Query 1 1476 use `test`; INSERT INTO t1 VALUES (1, "") -master-bin.000001 1476 Xid 1 1503 COMMIT /* XID */ -master-bin.000001 1503 Query 1 1571 BEGIN -master-bin.000001 1571 Query 1 1668 use `test`; INSERT INTO t1 VALUES (2, "first") -master-bin.000001 1668 Query 1 1766 use `test`; INSERT INTO t1 VALUES (2, "second") -master-bin.000001 1766 Xid 1 1793 COMMIT /* XID */ -master-bin.000001 1793 Query 1 1861 BEGIN -master-bin.000001 1861 Query 1 1953 use `test`; INSERT INTO t1 VALUES (3, "") -master-bin.000001 1953 Xid 1 1980 COMMIT /* XID */ -master-bin.000001 1980 Rotate 1 2024 master-bin.000002;pos=4 +master-bin.000001 4 Format_desc 1 246 Server ver: #, Binlog ver: # +master-bin.000001 246 Binlog_checkpoint 1 286 master-bin.000001 +master-bin.000001 286 Query 1 421 use `test`; CREATE TABLE t1 (a INT, b VARCHAR(100), PRIMARY KEY (a,b)) ENGINE=innodb +master-bin.000001 421 Query 1 533 use `test`; CREATE TABLE t2 (a INT PRIMARY KEY) ENGINE=myisam +master-bin.000001 533 Query 1 601 BEGIN +master-bin.000001 601 Query 1 689 use `test`; INSERT INTO t2 VALUES (2) +master-bin.000001 689 Query 1 758 COMMIT +master-bin.000001 758 Query 1 826 BEGIN +master-bin.000001 826 Query 1 918 use `test`; INSERT INTO t1 VALUES (0, "") +master-bin.000001 918 Xid 1 945 COMMIT /* XID */ +master-bin.000001 945 Query 1 1013 BEGIN +master-bin.000001 1013 Query 1 1101 use `test`; INSERT INTO t2 VALUES (3) +master-bin.000001 1101 Query 1 1170 COMMIT +master-bin.000001 1170 Query 1 1238 BEGIN +master-bin.000001 1238 Query 1 1330 use `test`; INSERT INTO t1 VALUES (4, "") +master-bin.000001 1330 Xid 1 1357 COMMIT /* XID */ +master-bin.000001 1357 Query 1 1425 BEGIN +master-bin.000001 1425 Query 1 1517 use `test`; INSERT INTO t1 VALUES (1, "") +master-bin.000001 1517 Xid 1 1544 COMMIT /* XID */ +master-bin.000001 1544 Query 1 1612 BEGIN +master-bin.000001 1612 Query 1 1709 use `test`; INSERT INTO t1 VALUES (2, "first") +master-bin.000001 1709 Query 1 1807 use `test`; INSERT INTO t1 VALUES (2, "second") +master-bin.000001 1807 Xid 1 1834 COMMIT /* XID */ +master-bin.000001 1834 Query 1 1902 BEGIN +master-bin.000001 1902 Query 1 1994 use `test`; INSERT INTO t1 VALUES (3, "") +master-bin.000001 1994 Xid 1 2021 COMMIT /* XID */ +master-bin.000001 2021 Rotate 1 2065 master-bin.000002;pos=4 DROP TABLE t1,t2; diff --git a/mysql-test/suite/innodb/r/group_commit_binlog_pos.result b/mysql-test/suite/innodb/r/group_commit_binlog_pos.result index d28ad1fd70e..29aa765c1b4 100644 --- a/mysql-test/suite/innodb/r/group_commit_binlog_pos.result +++ b/mysql-test/suite/innodb/r/group_commit_binlog_pos.result @@ -30,6 +30,6 @@ a 1 2 3 -InnoDB: Last MySQL binlog file position 0 906, file name ./master-bin.000001 +InnoDB: Last MySQL binlog file position 0 947, file name ./master-bin.000001 SET DEBUG_SYNC= 'RESET'; DROP TABLE t1; diff --git a/mysql-test/suite/innodb/r/group_commit_binlog_pos_no_optimize_thread.result b/mysql-test/suite/innodb/r/group_commit_binlog_pos_no_optimize_thread.result index da8cff142b8..3c3b0709331 100644 --- a/mysql-test/suite/innodb/r/group_commit_binlog_pos_no_optimize_thread.result +++ b/mysql-test/suite/innodb/r/group_commit_binlog_pos_no_optimize_thread.result @@ -31,6 +31,6 @@ a 1 2 3 -InnoDB: Last MySQL binlog file position 0 906, file name ./master-bin.000001 +InnoDB: Last MySQL binlog file position 0 947, file name ./master-bin.000001 SET DEBUG_SYNC= 'RESET'; DROP TABLE t1; diff --git a/mysql-test/suite/innodb/r/group_commit_crash.result b/mysql-test/suite/innodb/r/group_commit_crash.result index cd47ba62ff2..c084f854e79 100644 --- a/mysql-test/suite/innodb/r/group_commit_crash.result +++ b/mysql-test/suite/innodb/r/group_commit_crash.result @@ -36,7 +36,7 @@ COMMIT; Got one of the listed errors SELECT * FROM t1 ORDER BY id; a b c d id -SHOW BINLOG EVENTS LIMIT 2,1; +SHOW BINLOG EVENTS LIMIT 3,1; Log_name Pos Event_type Server_id End_log_pos Info delete from t1; SET binlog_format= mixed; @@ -58,7 +58,7 @@ a b c d 7 a b c d 8 a b c d 9 a b c d 10 -SHOW BINLOG EVENTS LIMIT 2,1; +SHOW BINLOG EVENTS LIMIT 3,1; Log_name Pos Event_type Server_id End_log_pos Info master-bin.000001 # Query 1 # use `test`; insert into t1 select * from t2 delete from t1; @@ -81,7 +81,7 @@ a b c d 7 a b c d 8 a b c d 9 a b c d 10 -SHOW BINLOG EVENTS LIMIT 2,1; +SHOW BINLOG EVENTS LIMIT 3,1; Log_name Pos Event_type Server_id End_log_pos Info master-bin.000001 # Query 1 # use `test`; insert into t1 select * from t2 delete from t1; @@ -104,7 +104,7 @@ a b c d 7 a b c d 8 a b c d 9 a b c d 10 -SHOW BINLOG EVENTS LIMIT 2,1; +SHOW BINLOG EVENTS LIMIT 3,1; Log_name Pos Event_type Server_id End_log_pos Info master-bin.000001 # Query 1 # use `test`; insert into t1 select * from t2 delete from t1; @@ -117,7 +117,7 @@ COMMIT; Got one of the listed errors SELECT * FROM t1 ORDER BY id; a b c d id -SHOW BINLOG EVENTS LIMIT 2,1; +SHOW BINLOG EVENTS LIMIT 3,1; Log_name Pos Event_type Server_id End_log_pos Info delete from t1; DROP TABLE t1; diff --git a/mysql-test/suite/innodb/r/group_commit_crash_no_optimize_thread.result b/mysql-test/suite/innodb/r/group_commit_crash_no_optimize_thread.result index c1ae510d45b..40c270a76d3 100644 --- a/mysql-test/suite/innodb/r/group_commit_crash_no_optimize_thread.result +++ b/mysql-test/suite/innodb/r/group_commit_crash_no_optimize_thread.result @@ -36,7 +36,7 @@ COMMIT; Got one of the listed errors SELECT * FROM t1 ORDER BY id; a b c d id -SHOW BINLOG EVENTS LIMIT 2,1; +SHOW BINLOG EVENTS LIMIT 3,1; Log_name Pos Event_type Server_id End_log_pos Info delete from t1; SET binlog_format= mixed; @@ -58,7 +58,7 @@ a b c d 7 a b c d 8 a b c d 9 a b c d 10 -SHOW BINLOG EVENTS LIMIT 2,1; +SHOW BINLOG EVENTS LIMIT 3,1; Log_name Pos Event_type Server_id End_log_pos Info master-bin.000001 # Query 1 # use `test`; insert into t1 select * from t2 delete from t1; @@ -81,7 +81,7 @@ a b c d 7 a b c d 8 a b c d 9 a b c d 10 -SHOW BINLOG EVENTS LIMIT 2,1; +SHOW BINLOG EVENTS LIMIT 3,1; Log_name Pos Event_type Server_id End_log_pos Info master-bin.000001 # Query 1 # use `test`; insert into t1 select * from t2 delete from t1; @@ -104,7 +104,7 @@ a b c d 7 a b c d 8 a b c d 9 a b c d 10 -SHOW BINLOG EVENTS LIMIT 2,1; +SHOW BINLOG EVENTS LIMIT 3,1; Log_name Pos Event_type Server_id End_log_pos Info master-bin.000001 # Query 1 # use `test`; insert into t1 select * from t2 delete from t1; @@ -117,7 +117,7 @@ COMMIT; Got one of the listed errors SELECT * FROM t1 ORDER BY id; a b c d id -SHOW BINLOG EVENTS LIMIT 2,1; +SHOW BINLOG EVENTS LIMIT 3,1; Log_name Pos Event_type Server_id End_log_pos Info delete from t1; DROP TABLE t1; diff --git a/mysql-test/suite/innodb/t/group_commit_crash.test b/mysql-test/suite/innodb/t/group_commit_crash.test index 12c92d19244..0a297e3c570 100644 --- a/mysql-test/suite/innodb/t/group_commit_crash.test +++ b/mysql-test/suite/innodb/t/group_commit_crash.test @@ -66,7 +66,7 @@ while ($numtests) # table and binlog should be in sync. SELECT * FROM t1 ORDER BY id; --replace_column 2 # 5 # - SHOW BINLOG EVENTS LIMIT 2,1; + SHOW BINLOG EVENTS LIMIT 3,1; delete from t1; diff --git a/mysql-test/suite/innodb/t/group_commit_crash_no_optimize_thread.test b/mysql-test/suite/innodb/t/group_commit_crash_no_optimize_thread.test index 2de09d6b0b6..4214c2a6b03 100644 --- a/mysql-test/suite/innodb/t/group_commit_crash_no_optimize_thread.test +++ b/mysql-test/suite/innodb/t/group_commit_crash_no_optimize_thread.test @@ -66,7 +66,7 @@ while ($numtests) # table and binlog should be in sync. SELECT * FROM t1 ORDER BY id; --replace_column 2 # 5 # - SHOW BINLOG EVENTS LIMIT 2,1; + SHOW BINLOG EVENTS LIMIT 3,1; delete from t1; diff --git a/mysql-test/suite/maria/maria-connect.result b/mysql-test/suite/maria/maria-connect.result index ed626a003f5..d79ebbdb86c 100644 --- a/mysql-test/suite/maria/maria-connect.result +++ b/mysql-test/suite/maria/maria-connect.result @@ -16,6 +16,7 @@ a 4 SHOW BINLOG EVENTS FROM <start_pos>; Log_name Pos Event_type Server_id End_log_pos Info +master-bin.000001 # Binlog_checkpoint 1 # master-bin.000001 master-bin.000001 # Query 1 # use `test`; CREATE TABLE t1 (a int primary key) master-bin.000001 # Query 1 # BEGIN master-bin.000001 # Query 1 # use `test`; insert t1 values (1),(2),(3) diff --git a/mysql-test/suite/perfschema/r/all_instances.result b/mysql-test/suite/perfschema/r/all_instances.result index caf4f49034f..7d3484fc887 100644 --- a/mysql-test/suite/perfschema/r/all_instances.result +++ b/mysql-test/suite/perfschema/r/all_instances.result @@ -77,6 +77,7 @@ wait/synch/mutex/sql/Master_info::sleep_lock wait/synch/mutex/sql/MDL_map::mutex wait/synch/mutex/sql/MDL_wait::LOCK_wait_status wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_index +wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_xid_list wait/synch/mutex/sql/MYSQL_RELAY_LOG::LOCK_index wait/synch/mutex/sql/Query_cache::structure_guard_mutex wait/synch/mutex/sql/Relay_log_info::data_lock @@ -129,6 +130,7 @@ wait/synch/cond/sql/Master_info::start_cond wait/synch/cond/sql/Master_info::stop_cond wait/synch/cond/sql/MDL_context::COND_wait_status wait/synch/cond/sql/MYSQL_BIN_LOG::COND_queue_busy +wait/synch/cond/sql/MYSQL_BIN_LOG::COND_xid_list wait/synch/cond/sql/MYSQL_BIN_LOG::update_cond wait/synch/cond/sql/MYSQL_RELAY_LOG::COND_queue_busy wait/synch/cond/sql/MYSQL_RELAY_LOG::update_cond diff --git a/mysql-test/suite/perfschema/r/relaylog.result b/mysql-test/suite/perfschema/r/relaylog.result index a1d10265f4d..f8ff902245c 100644 --- a/mysql-test/suite/perfschema/r/relaylog.result +++ b/mysql-test/suite/perfschema/r/relaylog.result @@ -56,10 +56,10 @@ where event_name like "%MYSQL_BIN_LOG%" and event_name not like "%MYSQL_BIN_LOG::update_cond" order by event_name; EVENT_NAME COUNT_STAR -wait/synch/cond/sql/MYSQL_BIN_LOG::COND_prep_xids NONE wait/synch/cond/sql/MYSQL_BIN_LOG::COND_queue_busy NONE +wait/synch/cond/sql/MYSQL_BIN_LOG::COND_xid_list NONE wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_index MANY -wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_prep_xids NONE +wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_xid_list MANY "Expect no slave relay log" select * from performance_schema.file_summary_by_instance where event_name like "%relaylog%" order by file_name; @@ -131,10 +131,10 @@ where event_name like "%MYSQL_BIN_LOG%" and event_name not like "%MYSQL_BIN_LOG::update_cond" order by event_name; EVENT_NAME COUNT_STAR -wait/synch/cond/sql/MYSQL_BIN_LOG::COND_prep_xids NONE wait/synch/cond/sql/MYSQL_BIN_LOG::COND_queue_busy NONE +wait/synch/cond/sql/MYSQL_BIN_LOG::COND_xid_list NONE wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_index MANY -wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_prep_xids NONE +wait/synch/mutex/sql/MYSQL_BIN_LOG::LOCK_xid_list MANY "Expect a slave relay log" select substring(file_name, locate("slave-", file_name)) as FILE_NAME, diff --git a/mysql-test/suite/rpl/r/rpl_checksum.result b/mysql-test/suite/rpl/r/rpl_checksum.result index ba5cb1b1b2b..9e561908a7b 100644 --- a/mysql-test/suite/rpl/r/rpl_checksum.result +++ b/mysql-test/suite/rpl/r/rpl_checksum.result @@ -71,7 +71,7 @@ insert into t1 values (1) /* will not be applied on slave due to simulation */; set @@global.debug_dbug='d,simulate_slave_unaware_checksum'; start slave; include/wait_for_slave_io_error.inc [errno=1236] -Last_IO_Error = 'Got fatal error 1236 from master when reading data from binary log: 'Slave can not handle replication events with the checksum that master is configured to log; the first event 'master-bin.000009' at 245, the last event read from 'master-bin.000010' at 245, the last byte read from 'master-bin.000010' at 245.'' +Last_IO_Error = 'Got fatal error 1236 from master when reading data from binary log: 'Slave can not handle replication events with the checksum that master is configured to log; the first event 'master-bin.000009' at 286, the last event read from 'master-bin.000010' at 246, the last byte read from 'master-bin.000010' at 246.'' select count(*) as zero from t1; zero 0 diff --git a/mysql-test/suite/rpl/r/rpl_mariadb_slave_capability.result b/mysql-test/suite/rpl/r/rpl_mariadb_slave_capability.result index 5eae28441c2..9af3d4bbfd2 100644 --- a/mysql-test/suite/rpl/r/rpl_mariadb_slave_capability.result +++ b/mysql-test/suite/rpl/r/rpl_mariadb_slave_capability.result @@ -54,7 +54,7 @@ master-bin.000002 # Query # # COMMIT SELECT * FROM t1; a 2 -show relaylog events in 'slave-relay-bin.000005' from <binlog_start> limit 3,5; +show relaylog events in 'slave-relay-bin.000005' from <binlog_start> limit 4,5; Log_name Pos Event_type Server_id End_log_pos Info slave-relay-bin.000005 # Query # # BEGIN slave-relay-bin.000005 # Query # # # Dummy ev diff --git a/mysql-test/suite/rpl/r/rpl_row_annotate_do.result b/mysql-test/suite/rpl/r/rpl_row_annotate_do.result index a7dc2a569a1..cb1aab28603 100644 --- a/mysql-test/suite/rpl/r/rpl_row_annotate_do.result +++ b/mysql-test/suite/rpl/r/rpl_row_annotate_do.result @@ -55,6 +55,7 @@ a b FLUSH LOGS; show binlog events in 'slave-bin.000001' from <start_pos>; Log_name Pos Event_type Server_id End_log_pos Info +slave-bin.000001 # Binlog_checkpoint 2 # slave-bin.000001 slave-bin.000001 # Query 1 # DROP DATABASE IF EXISTS test1 slave-bin.000001 # Query 1 # CREATE DATABASE test1 slave-bin.000001 # Query 1 # use `test1`; CREATE TABLE t1(a int primary key, b int) diff --git a/mysql-test/suite/rpl/r/rpl_row_annotate_dont.result b/mysql-test/suite/rpl/r/rpl_row_annotate_dont.result index 2a3b5b1870e..b7648fd8592 100644 --- a/mysql-test/suite/rpl/r/rpl_row_annotate_dont.result +++ b/mysql-test/suite/rpl/r/rpl_row_annotate_dont.result @@ -47,6 +47,7 @@ a b FLUSH LOGS; show binlog events in 'slave-bin.000001' from <start_pos>; Log_name Pos Event_type Server_id End_log_pos Info +slave-bin.000001 # Binlog_checkpoint 2 # slave-bin.000001 slave-bin.000001 # Query 1 # DROP DATABASE IF EXISTS test1 slave-bin.000001 # Query 1 # CREATE DATABASE test1 slave-bin.000001 # Query 1 # use `test1`; CREATE TABLE t1(a int primary key, b int) diff --git a/mysql-test/suite/rpl/r/rpl_row_show_relaylog_events.result b/mysql-test/suite/rpl/r/rpl_row_show_relaylog_events.result index 7c55e44ed59..8534bf00711 100644 --- a/mysql-test/suite/rpl/r/rpl_row_show_relaylog_events.result +++ b/mysql-test/suite/rpl/r/rpl_row_show_relaylog_events.result @@ -94,6 +94,7 @@ show relaylog events in 'slave-relay-bin.000003' from <binlog_start>; Log_name Pos Event_type Server_id End_log_pos Info slave-relay-bin.000003 # Rotate # # master-bin.000001;pos=4 slave-relay-bin.000003 # Format_desc # # SERVER_VERSION, BINLOG_VERSION +slave-relay-bin.000003 # Binlog_checkpoint # # master-bin.000001 slave-relay-bin.000003 # Query # # use `test`; CREATE TABLE t1 (a INT) slave-relay-bin.000003 # Query # # BEGIN slave-relay-bin.000003 # Table_map # # table_id: # (test.t1) @@ -115,8 +116,8 @@ slave-relay-bin.000003 # Rotate # # master-bin.000001;pos=4 show relaylog events in 'slave-relay-bin.000003' from <binlog_start> limit 1,3; Log_name Pos Event_type Server_id End_log_pos Info slave-relay-bin.000003 # Format_desc # # SERVER_VERSION, BINLOG_VERSION +slave-relay-bin.000003 # Binlog_checkpoint # # master-bin.000001 slave-relay-bin.000003 # Query # # use `test`; CREATE TABLE t1 (a INT) -slave-relay-bin.000003 # Query # # BEGIN ******** [slave] SHOW RELAYLOG EVENTS ******** show relaylog events from <binlog_start>; Log_name Pos Event_type Server_id End_log_pos Info @@ -185,6 +186,7 @@ show relaylog events in 'slave-relay-bin.000006' from <binlog_start>; Log_name Pos Event_type Server_id End_log_pos Info slave-relay-bin.000006 # Rotate # # master-bin.000002;pos=4 slave-relay-bin.000006 # Format_desc # # SERVER_VERSION, BINLOG_VERSION +slave-relay-bin.000006 # Binlog_checkpoint # # master-bin.000002 slave-relay-bin.000006 # Query # # use `test`; DROP TABLE `t1` /* generated by server */ ******** [slave] SHOW RELAYLOG EVENTS IN <FILE> LIMIT 1 ******** show relaylog events in 'slave-relay-bin.000006' from <binlog_start> limit 1; @@ -194,6 +196,7 @@ slave-relay-bin.000006 # Rotate # # master-bin.000002;pos=4 show relaylog events in 'slave-relay-bin.000006' from <binlog_start> limit 1,3; Log_name Pos Event_type Server_id End_log_pos Info slave-relay-bin.000006 # Format_desc # # SERVER_VERSION, BINLOG_VERSION +slave-relay-bin.000006 # Binlog_checkpoint # # master-bin.000002 slave-relay-bin.000006 # Query # # use `test`; DROP TABLE `t1` /* generated by server */ ******** [slave] SHOW RELAYLOG EVENTS ******** show relaylog events from <binlog_start>; diff --git a/mysql-test/suite/rpl/r/rpl_stm_mix_show_relaylog_events.result b/mysql-test/suite/rpl/r/rpl_stm_mix_show_relaylog_events.result index f706fa0fe75..a978c3c900c 100644 --- a/mysql-test/suite/rpl/r/rpl_stm_mix_show_relaylog_events.result +++ b/mysql-test/suite/rpl/r/rpl_stm_mix_show_relaylog_events.result @@ -82,6 +82,7 @@ show relaylog events in 'slave-relay-bin.000003' from <binlog_start>; Log_name Pos Event_type Server_id End_log_pos Info slave-relay-bin.000003 # Rotate # # master-bin.000001;pos=4 slave-relay-bin.000003 # Format_desc # # SERVER_VERSION, BINLOG_VERSION +slave-relay-bin.000003 # Binlog_checkpoint # # master-bin.000001 slave-relay-bin.000003 # Query # # use `test`; CREATE TABLE t1 (a INT) slave-relay-bin.000003 # Query # # BEGIN slave-relay-bin.000003 # Query # # use `test`; INSERT INTO t1 VALUES (1) @@ -100,8 +101,8 @@ slave-relay-bin.000003 # Rotate # # master-bin.000001;pos=4 show relaylog events in 'slave-relay-bin.000003' from <binlog_start> limit 1,3; Log_name Pos Event_type Server_id End_log_pos Info slave-relay-bin.000003 # Format_desc # # SERVER_VERSION, BINLOG_VERSION +slave-relay-bin.000003 # Binlog_checkpoint # # master-bin.000001 slave-relay-bin.000003 # Query # # use `test`; CREATE TABLE t1 (a INT) -slave-relay-bin.000003 # Query # # BEGIN ******** [slave] SHOW RELAYLOG EVENTS ******** show relaylog events from <binlog_start>; Log_name Pos Event_type Server_id End_log_pos Info @@ -164,6 +165,7 @@ show relaylog events in 'slave-relay-bin.000006' from <binlog_start>; Log_name Pos Event_type Server_id End_log_pos Info slave-relay-bin.000006 # Rotate # # master-bin.000002;pos=4 slave-relay-bin.000006 # Format_desc # # SERVER_VERSION, BINLOG_VERSION +slave-relay-bin.000006 # Binlog_checkpoint # # master-bin.000002 slave-relay-bin.000006 # Query # # use `test`; DROP TABLE `t1` /* generated by server */ ******** [slave] SHOW RELAYLOG EVENTS IN <FILE> LIMIT 1 ******** show relaylog events in 'slave-relay-bin.000006' from <binlog_start> limit 1; @@ -173,6 +175,7 @@ slave-relay-bin.000006 # Rotate # # master-bin.000002;pos=4 show relaylog events in 'slave-relay-bin.000006' from <binlog_start> limit 1,3; Log_name Pos Event_type Server_id End_log_pos Info slave-relay-bin.000006 # Format_desc # # SERVER_VERSION, BINLOG_VERSION +slave-relay-bin.000006 # Binlog_checkpoint # # master-bin.000002 slave-relay-bin.000006 # Query # # use `test`; DROP TABLE `t1` /* generated by server */ ******** [slave] SHOW RELAYLOG EVENTS ******** show relaylog events from <binlog_start>; diff --git a/mysql-test/suite/rpl/t/rpl_mariadb_slave_capability.test b/mysql-test/suite/rpl/t/rpl_mariadb_slave_capability.test index 77aa9341ff4..36f4defa252 100644 --- a/mysql-test/suite/rpl/t/rpl_mariadb_slave_capability.test +++ b/mysql-test/suite/rpl/t/rpl_mariadb_slave_capability.test @@ -61,7 +61,7 @@ connection slave; SELECT * FROM t1; let $binlog_file= query_get_value(SHOW SLAVE STATUS, Relay_Log_File, 1); let $binlog_start= 0; -let $binlog_limit=3,5; +let $binlog_limit=4,5; --source include/show_relaylog_events.inc --echo # Test that slave which cannot tolerate holes in binlog stream but diff --git a/mysql-test/t/mysqlbinlog2.test b/mysql-test/t/mysqlbinlog2.test index 740c4078f20..986e180db13 100644 --- a/mysql-test/t/mysqlbinlog2.test +++ b/mysql-test/t/mysqlbinlog2.test @@ -23,7 +23,7 @@ insert into t1 values(null, "b"); set timestamp=@a+2; --let $binlog_pos_760=query_get_value(SHOW MASTER STATUS, Position, 1) insert into t1 values(null, "c"); ---let $binlog_pos_951=query_get_value(SHOW BINLOG EVENTS in 'master-bin.000001' from $binlog_pos_760, Pos, 4) +--let $binlog_pos_951=query_get_value(SHOW BINLOG EVENTS in 'master-bin.000001' from $binlog_pos_760, Pos, 5) set timestamp=@a+4; insert into t1 values(null, "d"); insert into t1 values(null, "e"); @@ -31,8 +31,8 @@ insert into t1 values(null, "e"); flush logs; set timestamp=@a+1; # this could happen on a slave insert into t1 values(null, "f"); ---let $binlog_pos_135=query_get_value(SHOW BINLOG EVENTS in 'master-bin.000002', Pos, 3) ---let $binlog_pos_203=query_get_value(SHOW BINLOG EVENTS in 'master-bin.000002', Pos, 4) +--let $binlog_pos_135=query_get_value(SHOW BINLOG EVENTS in 'master-bin.000002', Pos, 4) +--let $binlog_pos_203=query_get_value(SHOW BINLOG EVENTS in 'master-bin.000002', Pos, 5) # delimiters are for easier debugging in future @@ -50,22 +50,22 @@ let $MYSQLD_DATADIR= `select @@datadir`; --disable_query_log select "--- offset --" as ""; --enable_query_log ---exec $MYSQL_BINLOG --short-form --offset=2 $MYSQLD_DATADIR/master-bin.000001 +--exec $MYSQL_BINLOG --short-form --offset=3 $MYSQLD_DATADIR/master-bin.000001 --disable_query_log select "--- start-position --" as ""; --enable_query_log -let $start_pos= `select @binlog_start_pos + 653`; +let $start_pos= `select @binlog_start_pos + 693`; --exec $MYSQL_BINLOG --short-form --start-position=$start_pos $MYSQLD_DATADIR/master-bin.000001 --disable_query_log select "--- stop-position --" as ""; --enable_query_log -let $stop_pos= `select @binlog_start_pos + 653`; +let $stop_pos= `select @binlog_start_pos + 693`; --exec $MYSQL_BINLOG --short-form --stop-position=$stop_pos $MYSQLD_DATADIR/master-bin.000001 --disable_query_log select "--- start and stop positions ---" as ""; --enable_query_log -let $start_pos= `select @binlog_start_pos + 653`; -let $stop_pos= `select @binlog_start_pos + 770`; +let $start_pos= `select @binlog_start_pos + 693`; +let $stop_pos= `select @binlog_start_pos + 810`; --exec $MYSQL_BINLOG --short-form --start-position=$start_pos --stop-position=$stop_pos $MYSQLD_DATADIR/master-bin.000001 --disable_query_log select "--- start-datetime --" as ""; @@ -88,16 +88,16 @@ flush logs; --disable_query_log select "--- offset --" as ""; --enable_query_log ---exec $MYSQL_BINLOG --short-form --offset=2 $MYSQLD_DATADIR/master-bin.000001 $MYSQLD_DATADIR/master-bin.000002 +--exec $MYSQL_BINLOG --short-form --offset=3 $MYSQLD_DATADIR/master-bin.000001 $MYSQLD_DATADIR/master-bin.000002 --disable_query_log select "--- start-position --" as ""; --enable_query_log -let $start_pos= `select @binlog_start_pos + 653`; +let $start_pos= `select @binlog_start_pos + 693`; --exec $MYSQL_BINLOG --short-form --start-position=$start_pos $MYSQLD_DATADIR/master-bin.000001 $MYSQLD_DATADIR/master-bin.000002 --disable_query_log select "--- stop-position --" as ""; --enable_query_log -let $stop_pos= `select @binlog_start_pos + 69`; +let $stop_pos= `select @binlog_start_pos + 109`; --exec $MYSQL_BINLOG --short-form --stop-position=$stop_pos $MYSQLD_DATADIR/master-bin.000001 $MYSQLD_DATADIR/master-bin.000002 --disable_query_log select "--- start-datetime --" as ""; @@ -117,22 +117,22 @@ select "--- Remote --" as ""; --disable_query_log select "--- offset --" as ""; --enable_query_log ---exec $MYSQL_BINLOG --short-form --offset=2 --read-from-remote-server --user=root --host=127.0.0.1 --port=$MASTER_MYPORT master-bin.000001 +--exec $MYSQL_BINLOG --short-form --offset=3 --read-from-remote-server --user=root --host=127.0.0.1 --port=$MASTER_MYPORT master-bin.000001 --disable_query_log select "--- start-position --" as ""; --enable_query_log -let $start_pos= `select @binlog_start_pos + 653`; +let $start_pos= `select @binlog_start_pos + 693`; --exec $MYSQL_BINLOG --short-form --start-position=$start_pos --read-from-remote-server --user=root --host=127.0.0.1 --port=$MASTER_MYPORT master-bin.000001 --disable_query_log select "--- stop-position --" as ""; --enable_query_log -let $stop_pos= `select @binlog_start_pos + 653`; +let $stop_pos= `select @binlog_start_pos + 693`; --exec $MYSQL_BINLOG --short-form --stop-position=$stop_pos --read-from-remote-server --user=root --host=127.0.0.1 --port=$MASTER_MYPORT master-bin.000001 --disable_query_log select "--- start and stop positions ---" as ""; --enable_query_log -let $start_pos= `select @binlog_start_pos + 653`; -let $stop_pos= `select @binlog_start_pos + 770`; +let $start_pos= `select @binlog_start_pos + 693`; +let $stop_pos= `select @binlog_start_pos + 810`; --exec $MYSQL_BINLOG --short-form --start-position=$start_pos --stop-position $stop_pos --read-from-remote-server --user=root --host=127.0.0.1 --port=$MASTER_MYPORT master-bin.000001 --disable_query_log select "--- start-datetime --" as ""; @@ -152,16 +152,16 @@ select "--- Remote with 2 binlogs on command line --" as ""; --disable_query_log select "--- offset --" as ""; --enable_query_log ---exec $MYSQL_BINLOG --short-form --offset=2 --read-from-remote-server --user=root --host=127.0.0.1 --port=$MASTER_MYPORT master-bin.000001 master-bin.000002 +--exec $MYSQL_BINLOG --short-form --offset=3 --read-from-remote-server --user=root --host=127.0.0.1 --port=$MASTER_MYPORT master-bin.000001 master-bin.000002 --disable_query_log select "--- start-position --" as ""; --enable_query_log -let $start_pos= `select @binlog_start_pos + 653`; +let $start_pos= `select @binlog_start_pos + 693`; --exec $MYSQL_BINLOG --short-form --start-position=$start_pos --read-from-remote-server --user=root --host=127.0.0.1 --port=$MASTER_MYPORT master-bin.000001 master-bin.000002 --disable_query_log select "--- stop-position --" as ""; --enable_query_log -let $stop_pos= `select @binlog_start_pos + 28`; +let $stop_pos= `select @binlog_start_pos + 68`; --exec $MYSQL_BINLOG --short-form --stop-position=$stop_pos --read-from-remote-server --user=root --host=127.0.0.1 --port=$MASTER_MYPORT master-bin.000001 master-bin.000002 --disable_query_log select "--- start-datetime --" as ""; diff --git a/mysql-test/t/mysqldump-max.test b/mysql-test/t/mysqldump-max.test index 27c1a3ce20c..d0a4870ba31 100644 --- a/mysql-test/t/mysqldump-max.test +++ b/mysql-test/t/mysqldump-max.test @@ -1194,7 +1194,7 @@ DROP TABLE t2; --exec $MYSQL test < $MYSQLTEST_VARDIR/tmp/mwl136.sql --replace_regex /\/\* xid=.* \*\//\/* XID *\// /Server ver: .*, Binlog ver: .*/Server ver: #, Binlog ver: #/ /table_id: [0-9]+/table_id: #/ -SHOW BINLOG EVENTS LIMIT 6,3; +SHOW BINLOG EVENTS LIMIT 7,3; --perl my $f= "$ENV{MYSQLTEST_VARDIR}/tmp/mwl136.sql"; open F, '<', $f or die "Failed to open $f: $!\n"; diff --git a/mysql-test/t/xa_binlog.test b/mysql-test/t/xa_binlog.test index 48f1dc6dfaa..430d45ab86a 100644 --- a/mysql-test/t/xa_binlog.test +++ b/mysql-test/t/xa_binlog.test @@ -27,6 +27,6 @@ SELECT * FROM t1 ORDER BY a; --replace_column 2 # 5 # --replace_regex /xid=[0-9]+/xid=XX/ -SHOW BINLOG EVENTS LIMIT 1,9; +SHOW BINLOG EVENTS LIMIT 2,9; DROP TABLE t1; diff --git a/sql/handler.cc b/sql/handler.cc index 58d37532796..e7eddef55ed 100644 --- a/sql/handler.cc +++ b/sql/handler.cc @@ -1286,6 +1286,7 @@ int ha_commit_trans(THD *thd, bool all) if (!cookie) goto err; + DEBUG_SYNC(thd, "ha_commit_trans_after_log_and_order"); DBUG_EXECUTE_IF("crash_commit_after_log", DBUG_SUICIDE();); error= commit_one_phase_2(thd, all, trans, is_real_trans) ? 2 : 0; diff --git a/sql/log.cc b/sql/log.cc index 56c07f81c9e..430f0a0bf60 100644 --- a/sql/log.cc +++ b/sql/log.cc @@ -479,6 +479,7 @@ public: */ bool using_xa; my_xid xa_xid; + ulong cookie; private: @@ -1665,6 +1666,21 @@ binlog_flush_cache(THD *thd, binlog_cache_mngr *cache_mngr, end_ev, all, using_stmt, using_trx); } + else + { + /* + This can happen in row-format binlog with something like + BEGIN; INSERT INTO nontrans_table; INSERT IGNORE INTO trans_table; + The nontrans_table is written directly into the binlog before commit, + and if the trans_table is ignored there will be no rows to write when + we get here. + + So there is no work to do. Therefore, we will not increment any XID + count, so we must not decrement any XID count in unlog(). + */ + if (cache_mngr->using_xa && cache_mngr->xa_xid) + cache_mngr->cookie= BINLOG_COOKIE_DUMMY; + } cache_mngr->reset(using_stmt, using_trx); DBUG_ASSERT((!using_stmt || cache_mngr->stmt_cache.empty()) && @@ -2888,7 +2904,8 @@ const char *MYSQL_LOG::generate_name(const char *log_name, MYSQL_BIN_LOG::MYSQL_BIN_LOG(uint *sync_period) - :bytes_written(0), prepared_xids(0), file_id(1), open_count(1), + :current_binlog_id(BINLOG_COOKIE_START), reset_master_pending(false), + bytes_written(0), file_id(1), open_count(1), need_start_event(TRUE), group_commit_queue(0), group_commit_queue_busy(FALSE), num_commits(0), num_group_commits(0), @@ -2916,13 +2933,30 @@ void MYSQL_BIN_LOG::cleanup() DBUG_ENTER("cleanup"); if (inited) { + xid_count_per_binlog *b; + inited= 0; close(LOG_CLOSE_INDEX|LOG_CLOSE_STOP_EVENT); delete description_event_for_queue; delete description_event_for_exec; + + while ((b= binlog_xid_count_list.get())) + { + /* + There should be no pending XIDs at shutdown, and only one entry (for + the active binlog file) in the list. + */ + DBUG_ASSERT(b->xid_count == 0); + DBUG_ASSERT(!binlog_xid_count_list.head()); + my_free(b); + } + mysql_mutex_destroy(&LOCK_log); mysql_mutex_destroy(&LOCK_index); + mysql_mutex_destroy(&LOCK_xid_list); mysql_cond_destroy(&update_cond); + mysql_cond_destroy(&COND_queue_busy); + mysql_cond_destroy(&COND_xid_list); } DBUG_VOID_RETURN; } @@ -2944,8 +2978,11 @@ void MYSQL_BIN_LOG::init_pthread_objects() MYSQL_LOG::init_pthread_objects(); mysql_mutex_init(m_key_LOCK_index, &LOCK_index, MY_MUTEX_INIT_SLOW); mysql_mutex_setflags(&LOCK_index, MYF_NO_DEADLOCK_DETECTION); + mysql_mutex_init(key_BINLOG_LOCK_xid_list, + &LOCK_xid_list, MY_MUTEX_INIT_FAST); mysql_cond_init(m_key_update_cond, &update_cond, 0); mysql_cond_init(m_key_COND_queue_busy, &COND_queue_busy, 0); + mysql_cond_init(key_BINLOG_COND_xid_list, &COND_xid_list, 0); } @@ -3149,6 +3186,51 @@ bool MYSQL_BIN_LOG::open(const char *log_name, if (s.write(&log_file)) goto err; bytes_written+= s.data_written; + + if (!is_relay_log) + { + char buf[FN_REFLEN]; + /* + Put this one into the list of active binlogs. + Write the current binlog checkpoint into the log, so XA recovery will + know from where to start recovery. + */ + uint off= dirname_length(log_file_name); + uint len= strlen(log_file_name) - off; + char *entry_mem, *name_mem; + xid_count_per_binlog *b, *b2; + if (!(b = (xid_count_per_binlog *) + my_multi_malloc(MYF(MY_WME), + &entry_mem, sizeof(xid_count_per_binlog), + &name_mem, len, + NULL))) + goto err; + memcpy(name_mem, log_file_name+off, len); + b->binlog_name= name_mem; + b->binlog_name_len= len; + b->xid_count= 0; + + mysql_mutex_lock(&LOCK_xid_list); + b->binlog_id= ++current_binlog_id; + + /* + Remove any initial entries with no pending XIDs. + Normally this will be done in unlog(), but if there are no + transactions with an XA-capable engine at all in a given binlog + file, unlog() will never be used and we will remove the entry here. + */ + while ((b2= binlog_xid_count_list.head()) && b2->xid_count == 0) + my_free(binlog_xid_count_list.get()); + + binlog_xid_count_list.push_back(b); + b2= binlog_xid_count_list.head(); + strmake(buf, b2->binlog_name, b2->binlog_name_len); + mysql_mutex_unlock(&LOCK_xid_list); + Binlog_checkpoint_log_event ev(buf, len); + if (ev.write(&log_file)) + goto err; + bytes_written+= ev.data_written; + } } if (description_event_for_queue && description_event_for_queue->binlog_version>=4) @@ -3514,6 +3596,42 @@ bool MYSQL_BIN_LOG::reset_logs(THD* thd) mysql_mutex_lock(&LOCK_log); mysql_mutex_lock(&LOCK_index); + if (!is_relay_log) + { + /* + We are going to nuke all binary log files. + So first wait until all pending binlog checkpoints have completed. + */ + mysql_mutex_lock(&LOCK_xid_list); + xid_count_per_binlog *b; + reset_master_pending= true; + for (;;) + { + I_List_iterator<xid_count_per_binlog> it(binlog_xid_count_list); + while ((b= it++)) + { + if (b->xid_count > 0) + break; + } + if (!b) + break; /* No more pending XIDs */ + /* + Wait until signalled that one more binlog dropped to zero, then check + again. + */ + mysql_cond_wait(&COND_xid_list, &LOCK_xid_list); + } + + /* + Now all XIDs are fully flushed to disk, and we are holding LOCK_log so + no new ones will be written. So we can proceed to delete the logs. + */ + while ((b= binlog_xid_count_list.get())) + my_free(b); + reset_master_pending= false; + mysql_mutex_unlock(&LOCK_xid_list); + } + /* The following mutex is needed to ensure that no threads call 'delete thd' as we would then risk missing a 'rollback' from this @@ -3824,8 +3942,7 @@ int MYSQL_BIN_LOG::purge_logs(const char *to_log, if ((error=find_log_pos(&log_info, NullS, 0 /*no mutex*/))) goto err; while ((strcmp(to_log,log_info.log_file_name) || (exit_loop=included)) && - !is_active(log_info.log_file_name) && - !log_in_use(log_info.log_file_name)) + can_purge_log(log_info.log_file_name)) { if ((error= register_purge_index_entry(log_info.log_file_name))) { @@ -4175,8 +4292,7 @@ int MYSQL_BIN_LOG::purge_logs_before_date(time_t purge_time) goto err; while (strcmp(log_file_name, log_info.log_file_name) && - !is_active(log_info.log_file_name) && - !log_in_use(log_info.log_file_name)) + can_purge_log(log_info.log_file_name)) { if (!mysql_file_stat(m_key_file_log, log_info.log_file_name, &stat_area, MYF(0))) @@ -4231,6 +4347,28 @@ err: mysql_mutex_unlock(&LOCK_index); DBUG_RETURN(error); } + + +bool +MYSQL_BIN_LOG::can_purge_log(const char *log_file_name) +{ + xid_count_per_binlog *b; + + if (is_active(log_file_name)) + return false; + mysql_mutex_lock(&LOCK_xid_list); + { + I_List_iterator<xid_count_per_binlog> it(binlog_xid_count_list); + while ((b= it++) && + 0 != strncmp(log_file_name+dirname_length(log_file_name), + b->binlog_name, b->binlog_name_len)) + ; + } + mysql_mutex_unlock(&LOCK_xid_list); + if (b) + return false; + return !log_in_use(log_file_name); +} #endif /* HAVE_REPLICATION */ @@ -4324,26 +4462,6 @@ int MYSQL_BIN_LOG::new_file_impl(bool need_lock) mysql_mutex_assert_owner(&LOCK_log); mysql_mutex_assert_owner(&LOCK_index); - /* - if binlog is used as tc log, be sure all xids are "unlogged", - so that on recover we only need to scan one - latest - binlog file - for prepared xids. As this is expected to be a rare event, - simple wait strategy is enough. We're locking LOCK_log to be sure no - new Xid_log_event's are added to the log (and prepared_xids is not - increased), and waiting on COND_prep_xids for late threads to - catch up. - */ - if (prepared_xids) - { - tc_log_page_waits++; - mysql_mutex_lock(&LOCK_prep_xids); - while (prepared_xids) { - DBUG_PRINT("info", ("prepared_xids=%lu", prepared_xids)); - mysql_cond_wait(&COND_prep_xids, &LOCK_prep_xids); - } - mysql_mutex_unlock(&LOCK_prep_xids); - } - /* Reuse old name if not binlog and not update log */ new_name_ptr= name; @@ -5792,6 +5910,37 @@ bool MYSQL_BIN_LOG::write_incident(THD *thd) DBUG_RETURN(error); } +void +MYSQL_BIN_LOG::write_binlog_checkpoint_event_already_locked(const char *name, + uint len) +{ + Binlog_checkpoint_log_event ev(name, len); + /* + Note that we must sync the binlog checkpoint to disk. + Otherwise a subsequent log purge could delete binlogs that XA recovery + thinks are needed (even though they are not really). + */ + if (!ev.write(&log_file) && !flush_and_sync(0)) + { + bool check_purge= false; + signal_update(); + rotate(false, &check_purge); + if (check_purge) + purge(); + return; + } + + /* + If we fail to write the checkpoint event, something is probably really + bad with the binlog. We complain in the error log. + Note that failure to write binlog checkpoint does not compromise the + ability to do crash recovery - crash recovery will just have to scan a + bit more of the binlog than strictly necessary. + */ + sql_print_error("Failed to write binlog checkpoint event to binary log\n"); +} + + /** Write a cached log entry to the binary log. - To support transaction over replication, we wrap the transaction @@ -5951,7 +6100,7 @@ MYSQL_BIN_LOG::write_transaction_to_binlog_events(group_commit_entry *entry) for a transaction if log_xid() fails). */ if (entry->cache_mngr->using_xa && entry->cache_mngr->xa_xid) - mark_xid_done(); + mark_xid_done(entry->cache_mngr->cookie); return 1; } @@ -5972,7 +6121,6 @@ MYSQL_BIN_LOG::trx_group_commit_leader(group_commit_entry *leader) uint xid_count= 0; my_off_t UNINIT_VAR(commit_offset); group_commit_entry *current; - group_commit_entry *last_in_queue; group_commit_entry *queue= NULL; bool check_purge= false; DBUG_ENTER("MYSQL_BIN_LOG::trx_group_commit_leader"); @@ -5993,7 +6141,6 @@ MYSQL_BIN_LOG::trx_group_commit_leader(group_commit_entry *leader) mysql_mutex_unlock(&LOCK_prepare_ordered); /* As the queue is in reverse order of entering, reverse it. */ - last_in_queue= current; while (current) { group_commit_entry *next= current->next; @@ -6032,7 +6179,10 @@ MYSQL_BIN_LOG::trx_group_commit_leader(group_commit_entry *leader) commit_offset= my_b_write_tell(&log_file); cache_mngr->last_commit_pos_offset= commit_offset; if (cache_mngr->using_xa && cache_mngr->xa_xid) + { xid_count++; + cache_mngr->cookie= current_binlog_id; + } } bool synced= 0; @@ -6075,16 +6225,14 @@ MYSQL_BIN_LOG::trx_group_commit_leader(group_commit_entry *leader) } /* - if any commit_events are Xid_log_event, increase the number of - prepared_xids (it's decreased in ::unlog()). Binlog cannot be rotated - if there're prepared xids in it - see the comment in new_file() for - an explanation. - If no Xid_log_events (then it's all Query_log_event) rotate binlog, - if necessary. + If any commit_events are Xid_log_event, increase the number of pending + XIDs in current binlog (it's decreased in ::unlog()). When the count in + a (not active) binlog file reaches zero, we know that it is no longer + needed in XA recovery, and we can log a new binlog checkpoint event. */ if (xid_count > 0) { - mark_xids_active(xid_count); + mark_xids_active(current_binlog_id, xid_count); } else { @@ -6092,11 +6240,11 @@ MYSQL_BIN_LOG::trx_group_commit_leader(group_commit_entry *leader) { /* If we fail to rotate, which thread should get the error? - We give the error to the *last* transaction thread; that seems to - make the most sense, as it was the last to write to the log. + We give the error to the leader, as any my_error() thrown inside + rotate() will have been registered for the leader THD. */ - last_in_queue->error= ER_ERROR_ON_WRITE; - last_in_queue->commit_errno= errno; + leader->error= ER_ERROR_ON_WRITE; + leader->commit_errno= errno; check_purge= false; } } @@ -6113,9 +6261,6 @@ MYSQL_BIN_LOG::trx_group_commit_leader(group_commit_entry *leader) */ mysql_mutex_unlock(&LOCK_log); - if (check_purge) - purge(); - DEBUG_SYNC(leader->thd, "commit_after_release_LOCK_log"); ++num_group_commits; @@ -6148,7 +6293,8 @@ MYSQL_BIN_LOG::trx_group_commit_leader(group_commit_entry *leader) DEBUG_SYNC(leader->thd, "commit_loop_entry_commit_ordered"); ++num_commits; - if (current->cache_mngr->using_xa && !current->error) + if (current->cache_mngr->using_xa && !current->error && + DBUG_EVALUATE_IF("skip_commit_ordered", 0, 1)) run_commit_ordered(current->thd, current->all); /* @@ -6163,6 +6309,9 @@ MYSQL_BIN_LOG::trx_group_commit_leader(group_commit_entry *leader) DEBUG_SYNC(leader->thd, "commit_after_group_run_commit_ordered"); mysql_mutex_unlock(&LOCK_commit_ordered); + if (check_purge) + purge(); + DBUG_VOID_RETURN; } @@ -7351,14 +7500,6 @@ int TC_LOG::using_heuristic_recover() /****** transaction coordinator log for 2pc - binlog() based solution ******/ #define TC_LOG_BINLOG MYSQL_BIN_LOG -/** - @todo - keep in-memory list of prepared transactions - (add to list in log(), remove on unlog()) - and copy it to the new binlog if rotated - but let's check the behaviour of tc_log_page_waits first! -*/ - int TC_LOG_BINLOG::open(const char *opt_name) { LOG_INFO log_info; @@ -7367,10 +7508,6 @@ int TC_LOG_BINLOG::open(const char *opt_name) DBUG_ASSERT(total_ha_2pc > 1); DBUG_ASSERT(opt_name && opt_name[0]); - mysql_mutex_init(key_BINLOG_LOCK_prep_xids, - &LOCK_prep_xids, MY_MUTEX_INIT_FAST); - mysql_cond_init(key_BINLOG_COND_prep_xids, &COND_prep_xids, 0); - if (!my_b_inited(&index_file)) { /* There was a failure to open the index file, can't open the binlog */ @@ -7429,7 +7566,8 @@ int TC_LOG_BINLOG::open(const char *opt_name) ev->flags & LOG_EVENT_BINLOG_IN_USE_F) { sql_print_information("Recovering after a crash using %s", opt_name); - error= recover(&log, (Format_description_log_event *)ev); + error= recover(&log_info, log_name, &log, + (Format_description_log_event *)ev); } else error=0; @@ -7449,9 +7587,6 @@ err: /** This is called on shutdown, after ha_panic. */ void TC_LOG_BINLOG::close() { - DBUG_ASSERT(prepared_xids==0); - mysql_mutex_destroy(&LOCK_prep_xids); - mysql_cond_destroy(&COND_prep_xids); } /* @@ -7471,11 +7606,23 @@ TC_LOG_BINLOG::log_and_order(THD *thd, my_xid xid, bool all, cache_mngr->using_xa= TRUE; cache_mngr->xa_xid= xid; +#ifndef DBUG_OFF + cache_mngr->cookie= 0; +#endif err= binlog_commit_flush_xid_caches(thd, cache_mngr, all, xid); DEBUG_SYNC(thd, "binlog_after_log_and_order"); - DBUG_RETURN(!err); + if (err) + DBUG_RETURN(0); + /* + If using explicit user XA, we will not have XID. We must still return a + non-zero cookie (as zero cookie signals error). + */ + if (!xid) + DBUG_RETURN(BINLOG_COOKIE_DUMMY); + DBUG_ASSERT(cache_mngr->cookie != 0); + DBUG_RETURN(cache_mngr->cookie); } /* @@ -7490,40 +7637,134 @@ TC_LOG_BINLOG::log_and_order(THD *thd, my_xid xid, bool all, binary log. */ void -TC_LOG_BINLOG::mark_xids_active(uint xid_count) +TC_LOG_BINLOG::mark_xids_active(ulong cookie, uint xid_count) { + xid_count_per_binlog *b; + DBUG_ENTER("TC_LOG_BINLOG::mark_xids_active"); - DBUG_PRINT("info", ("xid_count=%u", xid_count)); - mysql_mutex_lock(&LOCK_prep_xids); - prepared_xids+= xid_count; - mysql_mutex_unlock(&LOCK_prep_xids); + DBUG_PRINT("info", ("cookie=%lu xid_count=%u", cookie, xid_count)); + DBUG_ASSERT(cookie != 0 && cookie != BINLOG_COOKIE_DUMMY); + + mysql_mutex_lock(&LOCK_xid_list); + I_List_iterator<xid_count_per_binlog> it(binlog_xid_count_list); + while ((b= it++)) + { + if (b->binlog_id == cookie) + { + b->xid_count += xid_count; + break; + } + } + /* + As we do not delete elements until count reach zero, elements should always + be found. + */ + DBUG_ASSERT(b); + mysql_mutex_unlock(&LOCK_xid_list); DBUG_VOID_RETURN; } /* - Once an XID is committed, it is safe to rotate the binary log, as it can no - longer be needed during crash recovery. + Once an XID is committed, it can no longer be needed during crash recovery, + as it has been durably recorded on disk as "committed". This function is called to mark an XID this way. It needs to decrease the - count of pending XIDs, and signal the log rotator thread when it reaches zero. + count of pending XIDs in the corresponding binlog. When the count reaches + zero (for an "old" binlog that is not the active one), that binlog file no + longer need to be scanned during crash recovery, so we can log a new binlog + checkpoint. */ void -TC_LOG_BINLOG::mark_xid_done() +TC_LOG_BINLOG::mark_xid_done(ulong cookie) { - my_bool send_signal; + xid_count_per_binlog *b; + bool first; + ulong current; DBUG_ENTER("TC_LOG_BINLOG::mark_xid_done"); - mysql_mutex_lock(&LOCK_prep_xids); - // prepared_xids can be 0 if the transaction had ignorable errors. - DBUG_ASSERT(prepared_xids >= 0); - if (prepared_xids > 0) - prepared_xids--; - send_signal= (prepared_xids == 0); - mysql_mutex_unlock(&LOCK_prep_xids); - if (send_signal) { - DBUG_PRINT("info", ("prepared_xids=%lu", prepared_xids)); - mysql_cond_signal(&COND_prep_xids); + if (cookie == BINLOG_COOKIE_DUMMY) + DBUG_VOID_RETURN; /* Nothing to do. */ + + mysql_mutex_lock(&LOCK_xid_list); + current= current_binlog_id; + I_List_iterator<xid_count_per_binlog> it(binlog_xid_count_list); + first= true; + while ((b= it++)) + { + if (b->binlog_id == cookie) + { + --b->xid_count; + break; + } + first= false; + } + /* Binlog is always found, as we do not remove until count reaches 0 */ + DBUG_ASSERT(b); + if (likely(cookie == current && !reset_master_pending) || + b->xid_count != 0 || !first) + { + /* No new binlog checkpoint reached yet. */ + mysql_mutex_unlock(&LOCK_xid_list); + DBUG_VOID_RETURN; + } + + /* + Now log a binlog checkpoint for the first binlog file with a non-zero count. + + Note that it is possible (though perhaps unlikely) that when count of + binlog (N-2) drops to zero, binlog (N-1) is already at zero. So we may + need to skip several entries before we find the one to log in the binlog + checkpoint event. + + We chain the locking of LOCK_xid_list and LOCK_log, so that we ensure that + Binlog_checkpoint_events are logged in order. This simplifies recovery a + bit, as it can just take the last binlog checkpoint in the log, rather + than compare all found against each other to find the one pointing to the + most recent binlog. + + Note also that we need to first release LOCK_xid_list, then aquire + LOCK_log, then re-aquire LOCK_xid_list. If we were to take LOCK_log while + holding LOCK_xid_list, we might deadlock with other threads that take the + locks in the opposite order. + + If a RESET MASTER is pending, we are about to remove all log files, and + the RESET MASTER thread is waiting for all pending unlog() calls to + complete while holding LOCK_log. In this case we should not log a binlog + checkpoint event (it would be deleted immediately anywat and we would + deadlock on LOCK_log) but just signal the thread. + */ + if (!reset_master_pending) + { + mysql_mutex_unlock(&LOCK_xid_list); + mysql_mutex_lock(&LOCK_log); + mysql_mutex_lock(&LOCK_xid_list); + } + for (;;) + { + /* Remove initial element(s) with zero count. */ + b= binlog_xid_count_list.head(); + /* + Normally, we must not remove all elements in the list. + Only if a RESET MASTER is in progress may we delete everything - RESET + MASTER has LOCK_log held, and will create a new initial element before + releasing the lock. + */ + DBUG_ASSERT(b || reset_master_pending); + if (unlikely(!b) || b->binlog_id == current || b->xid_count > 0) + break; + my_free(binlog_xid_count_list.get()); } + if (reset_master_pending) + { + mysql_cond_signal(&COND_xid_list); + mysql_mutex_unlock(&LOCK_xid_list); + DBUG_VOID_RETURN; + } + + mysql_mutex_unlock(&LOCK_xid_list); + write_binlog_checkpoint_event_already_locked(b->binlog_name, + b->binlog_name_len); + mysql_mutex_unlock(&LOCK_log); DBUG_VOID_RETURN; } @@ -7531,16 +7772,24 @@ int TC_LOG_BINLOG::unlog(ulong cookie, my_xid xid) { DBUG_ENTER("TC_LOG_BINLOG::unlog"); if (xid) - mark_xid_done(); + mark_xid_done(cookie); /* As ::write_transaction_to_binlog() did not rotate, do it here. */ DBUG_RETURN(rotate_and_purge(0)); } -int TC_LOG_BINLOG::recover(IO_CACHE *log, Format_description_log_event *fdle) +int TC_LOG_BINLOG::recover(LOG_INFO *linfo, const char *last_log_name, + IO_CACHE *first_log, + Format_description_log_event *fdle) { Log_event *ev; HASH xids; MEM_ROOT mem_root; + char binlog_checkpoint_name[FN_REFLEN]; + bool binlog_checkpoint_found; + bool first_round; + IO_CACHE log; + File file= -1; + const char *errmsg; if (! fdle->is_valid() || my_hash_init(&xids, &my_charset_bin, TC_LOG_PAGE_SIZE/3, 0, @@ -7551,19 +7800,109 @@ int TC_LOG_BINLOG::recover(IO_CACHE *log, Format_description_log_event *fdle) fdle->flags&= ~LOG_EVENT_BINLOG_IN_USE_F; // abort on the first error - while ((ev= Log_event::read_log_event(log, 0, fdle, - opt_master_verify_checksum)) - && ev->is_valid()) + /* + Scan the binlog for XIDs that need to be committed if still in the + prepared stage. + + Start with the latest binlog file, then continue with any other binlog + files if the last found binlog checkpoint indicates it is needed. + */ + + binlog_checkpoint_found= false; + first_round= true; + for (;;) { - if (ev->get_type_code() == XID_EVENT) + while ((ev= Log_event::read_log_event(first_round ? first_log : &log, + 0, fdle, opt_master_verify_checksum)) + && ev->is_valid()) + { + switch (ev->get_type_code()) + { + case XID_EVENT: + { + Xid_log_event *xev=(Xid_log_event *)ev; + uchar *x= (uchar *) memdup_root(&mem_root, (uchar*) &xev->xid, + sizeof(xev->xid)); + if (!x || my_hash_insert(&xids, x)) + { + delete ev; + goto err2; + } + break; + } + case BINLOG_CHECKPOINT_EVENT: + if (first_round) + { + uint dir_len; + Binlog_checkpoint_log_event *cev= (Binlog_checkpoint_log_event *)ev; + if (cev->binlog_file_len >= FN_REFLEN) + sql_print_warning("Incorrect binlog checkpoint event with too " + "long file name found."); + else + { + /* + Note that we cannot use make_log_name() here, as we have not yet + initialised MYSQL_BIN_LOG::log_file_name. + */ + dir_len= dirname_length(last_log_name); + strmake(strnmov(binlog_checkpoint_name, last_log_name, dir_len), + cev->binlog_file_name, FN_REFLEN - 1 - dir_len); + binlog_checkpoint_found= true; + } + break; + } + default: + /* Nothing. */ + break; + } + delete ev; + } + + /* + If the last binlog checkpoint event points to an older log, we have to + scan all logs from there also, to get all possible XIDs to recover. + + If there was no binlog checkpoint event at all, this means the log was + written by an older version of MariaDB (or MySQL) - these always have an + (implicit) binlog checkpoint event at the start of the last binlog file. + */ + if (first_round) { - Xid_log_event *xev=(Xid_log_event *)ev; - uchar *x= (uchar *) memdup_root(&mem_root, (uchar*) &xev->xid, - sizeof(xev->xid)); - if (!x || my_hash_insert(&xids, x)) + if (!binlog_checkpoint_found) + break; + first_round= false; + if (find_log_pos(linfo, binlog_checkpoint_name, 1)) + { + sql_print_error("Binlog file '%s' not found in binlog index, needed " + "for recovery. Aborting.", binlog_checkpoint_name); goto err2; + } + } + else + { + end_io_cache(&log); + mysql_file_close(file, MYF(MY_WME)); + file= -1; + } + + if (0 == strcmp(linfo->log_file_name, last_log_name)) + break; // No more files to do + if ((file= open_binlog(&log, linfo->log_file_name, &errmsg)) < 0) + { + sql_print_error("%s", errmsg); + goto err2; + } + /* + We do not need to read the Format_description_log_event of other binlog + files. It is not possible for a binlog checkpoint to span multiple + binlog files written by different versions of the server. So we can use + the first one read for reading from all binlog files. + */ + if (find_next_log(linfo, 1)) + { + sql_print_error("Error reading binlog files during recovery. Aborting."); + goto err2; } - delete ev; } if (ha_recover(&xids)) @@ -7574,6 +7913,11 @@ int TC_LOG_BINLOG::recover(IO_CACHE *log, Format_description_log_event *fdle) return 0; err2: + if (file >= 0) + { + end_io_cache(&log); + mysql_file_close(file, MYF(MY_WME)); + } free_root(&mem_root, MYF(0)); my_hash_free(&xids); err1: diff --git a/sql/log.h b/sql/log.h index 9b9bed1262a..179d302d2cc 100644 --- a/sql/log.h +++ b/sql/log.h @@ -354,6 +354,15 @@ private: time_t last_time; }; +/* + We assign each binlog file an internal ID, used to identify them for unlog(). + Ids start from BINLOG_COOKIE_START; the value BINLOG_COOKIE_DUMMY is special + meaning "no binlog" (we cannot use zero as that is reserved for error return + from log_and_order). +*/ +#define BINLOG_COOKIE_DUMMY 1 +#define BINLOG_COOKIE_START 2 + class binlog_cache_mngr; class MYSQL_BIN_LOG: public TC_LOG, private MYSQL_LOG { @@ -394,10 +403,40 @@ class MYSQL_BIN_LOG: public TC_LOG, private MYSQL_LOG bool all; }; + /* + A list of struct xid_count_per_binlog is used to keep track of how many + XIDs are in prepared, but not committed, state in each binlog. + + When count drops to zero in a binlog after rotation, it means that there + are no more XIDs in prepared state, so that binlog is no longer needed + for XA crash recovery, and we can log a new binlog checkpoint event. + + The list is protected against simultaneous access from multiple + threads by LOCK_xid_list. + */ + struct xid_count_per_binlog : public ilink { + char *binlog_name; + uint binlog_name_len; + ulong binlog_id; + long xid_count; + xid_count_per_binlog(); /* Give link error if constructor used. */ + }; + ulong current_binlog_id; + I_List<xid_count_per_binlog> binlog_xid_count_list; + /* + When this is set, a RESET MASTER is in progress. + + Then we should not write any binlog checkpoints into the binlog (that + could result in deadlock on LOCK_log, and we will delete all binlog files + anyway). Instead we should signal COND_xid_list whenever a new binlog + checkpoint arrives - when all have arrived, RESET MASTER will complete. + */ + bool reset_master_pending; + /* LOCK_log and LOCK_index are inited by init_pthread_objects() */ mysql_mutex_t LOCK_index; - mysql_mutex_t LOCK_prep_xids; - mysql_cond_t COND_prep_xids; + mysql_mutex_t LOCK_xid_list; + mysql_cond_t COND_xid_list; mysql_cond_t update_cond; ulonglong bytes_written; IO_CACHE index_file; @@ -421,7 +460,6 @@ class MYSQL_BIN_LOG: public TC_LOG, private MYSQL_LOG fix_max_relay_log_size). */ ulong max_size; - long prepared_xids; /* for tc log - number of xids to remember */ // current file sequence number for load data infile binary logging uint file_id; uint open_count; // For replication @@ -473,8 +511,8 @@ class MYSQL_BIN_LOG: public TC_LOG, private MYSQL_LOG int write_transaction_or_stmt(group_commit_entry *entry); bool write_transaction_to_binlog_events(group_commit_entry *entry); void trx_group_commit_leader(group_commit_entry *leader); - void mark_xid_done(); - void mark_xids_active(uint xid_count); + void mark_xid_done(ulong cookie); + void mark_xids_active(ulong cookie, uint xid_count); public: using MYSQL_LOG::generate_name; @@ -562,7 +600,8 @@ public: int log_and_order(THD *thd, my_xid xid, bool all, bool need_prepare_ordered, bool need_commit_ordered); int unlog(ulong cookie, my_xid xid); - int recover(IO_CACHE *log, Format_description_log_event *fdle); + int recover(LOG_INFO *linfo, const char *last_log_name, IO_CACHE *first_log, + Format_description_log_event *fdle); #if !defined(MYSQL_CLIENT) int flush_and_set_pending_rows_event(THD *thd, Rows_log_event* event, @@ -614,6 +653,7 @@ public: bool write_incident_already_locked(THD *thd); bool write_incident(THD *thd); + void write_binlog_checkpoint_event_already_locked(const char *name, uint len); int write_cache(THD *thd, IO_CACHE *cache); void set_write_error(THD *thd, bool is_transactional); bool check_write_error(THD *thd); @@ -631,6 +671,7 @@ public: void make_log_name(char* buf, const char* log_ident); bool is_active(const char* log_file_name); + bool can_purge_log(const char *log_file_name); int update_log_index(LOG_INFO* linfo, bool need_update_threads); int rotate(bool force_rotate, bool* check_purge); void purge(); diff --git a/sql/log_event.cc b/sql/log_event.cc index f9849fa0ff5..6cefdb4fa59 100644 --- a/sql/log_event.cc +++ b/sql/log_event.cc @@ -731,6 +731,7 @@ const char* Log_event::get_type_str(Log_event_type type) case EXECUTE_LOAD_QUERY_EVENT: return "Execute_load_query"; case INCIDENT_EVENT: return "Incident"; case ANNOTATE_ROWS_EVENT: return "Annotate_rows"; + case BINLOG_CHECKPOINT_EVENT: return "Binlog_checkpoint"; default: return "Unknown"; /* impossible */ } } @@ -1387,7 +1388,7 @@ err: DBUG_ASSERT(error != 0); sql_print_error("Error in Log_event::read_log_event(): " "'%s', data_len: %d, event_type: %d", - error,data_len,head[EVENT_TYPE_OFFSET]); + error,data_len,(uchar)(head[EVENT_TYPE_OFFSET])); my_free(buf); /* The SQL slave thread will check if file->error<0 to know @@ -1536,6 +1537,9 @@ Log_event* Log_event::read_log_event(const char* buf, uint event_len, case ROTATE_EVENT: ev = new Rotate_log_event(buf, event_len, description_event); break; + case BINLOG_CHECKPOINT_EVENT: + ev = new Binlog_checkpoint_log_event(buf, event_len, description_event); + break; #ifdef HAVE_REPLICATION case SLAVE_EVENT: /* can never happen (unused event) */ ev = new Slave_log_event(buf, event_len, description_event); @@ -4405,6 +4409,8 @@ Format_description_log_event(uint8 binlog_ver, const char* server_ver) // Set header lengths of Maria events post_header_len[ANNOTATE_ROWS_EVENT-1]= ANNOTATE_ROWS_HEADER_LEN; + post_header_len[BINLOG_CHECKPOINT_EVENT-1]= + BINLOG_CHECKPOINT_HEADER_LEN; // Sanity-check that all post header lengths are initialized. int i; @@ -5864,6 +5870,86 @@ Rotate_log_event::do_shall_skip(Relay_log_info *rli) /************************************************************************** + Binlog_checkpoint_log_event methods +**************************************************************************/ + +#if defined(HAVE_REPLICATION) && !defined(MYSQL_CLIENT) +void Binlog_checkpoint_log_event::pack_info(Protocol *protocol) +{ + protocol->store(binlog_file_name, binlog_file_len, &my_charset_bin); +} +#endif + + +#ifdef MYSQL_CLIENT +void Binlog_checkpoint_log_event::print(FILE *file, + PRINT_EVENT_INFO *print_event_info) +{ + Write_on_release_cache cache(&print_event_info->head_cache, file, + Write_on_release_cache::FLUSH_F); + + if (print_event_info->short_form) + return; + print_header(&cache, print_event_info, FALSE); + my_b_printf(&cache, "\tBinlog checkpoint "); + my_b_write(&cache, (uchar*)binlog_file_name, binlog_file_len); + my_b_printf(&cache, "\n"); +} +#endif /* MYSQL_CLIENT */ + + +#ifdef MYSQL_SERVER +Binlog_checkpoint_log_event::Binlog_checkpoint_log_event( + const char *binlog_file_name_arg, + uint binlog_file_len_arg) + :Log_event(), + binlog_file_name(my_strndup(binlog_file_name_arg, binlog_file_len_arg, + MYF(MY_WME))), + binlog_file_len(binlog_file_len_arg) +{ + cache_type= EVENT_NO_CACHE; +} +#endif /* MYSQL_SERVER */ + + +Binlog_checkpoint_log_event::Binlog_checkpoint_log_event( + const char *buf, uint event_len, + const Format_description_log_event *description_event) + :Log_event(buf, description_event), binlog_file_name(0) +{ + uint8 header_size= description_event->common_header_len; + uint8 post_header_len= + description_event->post_header_len[BINLOG_CHECKPOINT_EVENT-1]; + if (event_len < header_size + post_header_len || + post_header_len < BINLOG_CHECKPOINT_HEADER_LEN) + return; + buf+= header_size; + /* See uint4korr and int4store below */ + compile_time_assert(BINLOG_CHECKPOINT_HEADER_LEN == 4); + binlog_file_len= uint4korr(buf); + if (event_len - (header_size + post_header_len) < binlog_file_len) + return; + binlog_file_name= my_strndup(buf + post_header_len, binlog_file_len, + MYF(MY_WME)); + return; +} + + +#ifndef MYSQL_CLIENT +bool Binlog_checkpoint_log_event::write(IO_CACHE *file) +{ + uchar buf[BINLOG_CHECKPOINT_HEADER_LEN]; + int4store(buf, binlog_file_len); + return write_header(file, BINLOG_CHECKPOINT_HEADER_LEN + binlog_file_len) || + wrapper_my_b_safe_write(file, buf, BINLOG_CHECKPOINT_HEADER_LEN) || + wrapper_my_b_safe_write(file, (const uchar *)binlog_file_name, + binlog_file_len) || + write_footer(file); +} +#endif /* MYSQL_CLIENT */ + + +/************************************************************************** Intvar_log_event methods **************************************************************************/ diff --git a/sql/log_event.h b/sql/log_event.h index 12d5e1417f4..c76e538618b 100644 --- a/sql/log_event.h +++ b/sql/log_event.h @@ -259,6 +259,7 @@ struct sql_ex_info #define INCIDENT_HEADER_LEN 2 #define HEARTBEAT_HEADER_LEN 0 #define ANNOTATE_ROWS_HEADER_LEN 0 +#define BINLOG_CHECKPOINT_HEADER_LEN 4 /* Max number of possible extra bytes in a replication event compared to a @@ -685,6 +686,14 @@ enum Log_event_type MARIA_EVENTS_BEGIN= 160, /* New Maria event numbers start from here */ ANNOTATE_ROWS_EVENT= 160, + /* + Binlog checkpoint event. Used for XA crash recovery on the master, not used + in replication. + A binlog checkpoint event specifies a binlog file such that XA crash + recovery can start from that file - and it is guaranteed to find all XIDs + that are prepared in storage engines but not yet committed. + */ + BINLOG_CHECKPOINT_EVENT= 161, /* Add new MariaDB events here - right above this comment! */ @@ -2892,6 +2901,32 @@ private: }; +class Binlog_checkpoint_log_event: public Log_event +{ +public: + char *binlog_file_name; + uint binlog_file_len; + +#ifdef MYSQL_SERVER + Binlog_checkpoint_log_event(const char *binlog_file_name_arg, + uint binlog_file_len_arg); +#ifdef HAVE_REPLICATION + void pack_info(Protocol *protocol); +#endif +#else + void print(FILE *file, PRINT_EVENT_INFO *print_event_info); +#endif + Binlog_checkpoint_log_event(const char *buf, uint event_len, + const Format_description_log_event *description_event); + ~Binlog_checkpoint_log_event() { my_free(binlog_file_name); } + Log_event_type get_type_code() { return BINLOG_CHECKPOINT_EVENT;} + int get_data_size() { return binlog_file_len + BINLOG_CHECKPOINT_HEADER_LEN;} + bool is_valid() const { return binlog_file_name != 0; } +#ifdef MYSQL_SERVER + bool write(IO_CACHE* file); +#endif +}; + /* the classes below are for the new LOAD DATA INFILE logging */ /** diff --git a/sql/mysqld.cc b/sql/mysqld.cc index 91bc2bfe226..3c0f209235a 100644 --- a/sql/mysqld.cc +++ b/sql/mysqld.cc @@ -722,7 +722,7 @@ PSI_mutex_key key_PAGE_lock, key_LOCK_sync, key_LOCK_active, key_LOCK_pool; PSI_mutex_key key_LOCK_des_key_file; #endif /* HAVE_OPENSSL */ -PSI_mutex_key key_BINLOG_LOCK_index, key_BINLOG_LOCK_prep_xids, +PSI_mutex_key key_BINLOG_LOCK_index, key_BINLOG_LOCK_xid_list, key_delayed_insert_mutex, key_hash_filo_lock, key_LOCK_active_mi, key_LOCK_connection_count, key_LOCK_crypt, key_LOCK_delayed_create, key_LOCK_delayed_insert, key_LOCK_delayed_status, key_LOCK_error_log, @@ -763,7 +763,7 @@ static PSI_mutex_info all_server_mutexes[]= #endif /* HAVE_OPENSSL */ { &key_BINLOG_LOCK_index, "MYSQL_BIN_LOG::LOCK_index", 0}, - { &key_BINLOG_LOCK_prep_xids, "MYSQL_BIN_LOG::LOCK_prep_xids", 0}, + { &key_BINLOG_LOCK_xid_list, "MYSQL_BIN_LOG::LOCK_xid_list", 0}, { &key_RELAYLOG_LOCK_index, "MYSQL_RELAY_LOG::LOCK_index", 0}, { &key_delayed_insert_mutex, "Delayed_insert::mutex", 0}, { &key_hash_filo_lock, "hash_filo::lock", 0}, @@ -831,7 +831,7 @@ static PSI_rwlock_info all_server_rwlocks[]= PSI_cond_key key_PAGE_cond, key_COND_active, key_COND_pool; #endif /* HAVE_MMAP */ -PSI_cond_key key_BINLOG_COND_prep_xids, key_BINLOG_update_cond, +PSI_cond_key key_BINLOG_COND_xid_list, key_BINLOG_update_cond, key_COND_cache_status_changed, key_COND_manager, key_COND_rpl_status, key_COND_server_started, key_delayed_insert_cond, key_delayed_insert_cond_client, @@ -859,7 +859,7 @@ static PSI_cond_info all_server_conds[]= { &key_COND_pool, "TC_LOG_MMAP::COND_pool", 0}, { &key_TC_LOG_MMAP_COND_queue_busy, "TC_LOG_MMAP::COND_queue_busy", 0}, #endif /* HAVE_MMAP */ - { &key_BINLOG_COND_prep_xids, "MYSQL_BIN_LOG::COND_prep_xids", 0}, + { &key_BINLOG_COND_xid_list, "MYSQL_BIN_LOG::COND_xid_list", 0}, { &key_BINLOG_update_cond, "MYSQL_BIN_LOG::update_cond", 0}, { &key_BINLOG_COND_queue_busy, "MYSQL_BIN_LOG::COND_queue_busy", 0}, { &key_RELAYLOG_update_cond, "MYSQL_RELAY_LOG::update_cond", 0}, diff --git a/sql/mysqld.h b/sql/mysqld.h index 56419acdcd4..28c4d771a48 100644 --- a/sql/mysqld.h +++ b/sql/mysqld.h @@ -225,7 +225,7 @@ extern PSI_mutex_key key_PAGE_lock, key_LOCK_sync, key_LOCK_active, extern PSI_mutex_key key_LOCK_des_key_file; #endif -extern PSI_mutex_key key_BINLOG_LOCK_index, key_BINLOG_LOCK_prep_xids, +extern PSI_mutex_key key_BINLOG_LOCK_index, key_BINLOG_LOCK_xid_list, key_delayed_insert_mutex, key_hash_filo_lock, key_LOCK_active_mi, key_LOCK_connection_count, key_LOCK_crypt, key_LOCK_delayed_create, key_LOCK_delayed_insert, key_LOCK_delayed_status, key_LOCK_error_log, @@ -256,7 +256,7 @@ extern PSI_rwlock_key key_rwlock_LOCK_grant, key_rwlock_LOCK_logger, extern PSI_cond_key key_PAGE_cond, key_COND_active, key_COND_pool; #endif /* HAVE_MMAP */ -extern PSI_cond_key key_BINLOG_COND_prep_xids, key_BINLOG_update_cond, +extern PSI_cond_key key_BINLOG_COND_xid_list, key_BINLOG_update_cond, key_COND_cache_status_changed, key_COND_manager, key_COND_rpl_status, key_COND_server_started, key_delayed_insert_cond, key_delayed_insert_cond_client, diff --git a/sql/sql_repl.cc b/sql/sql_repl.cc index d7308eddb7f..079aab27101 100644 --- a/sql/sql_repl.cc +++ b/sql/sql_repl.cc @@ -624,6 +624,30 @@ send_event_to_slave(THD *thd, NET *net, String* const packet, ushort flags, } /* + Do not send binlog checkpoint events to a slave that does not understand it. + */ + if (unlikely(event_type == BINLOG_CHECKPOINT_EVENT) && + mariadb_slave_capability < MARIA_SLAVE_CAPABILITY_BINLOG_CHECKPOINT) + { + if (mariadb_slave_capability >= MARIA_SLAVE_CAPABILITY_TOLERATE_HOLES) + { + /* This slave can tolerate events omitted from the binlog stream. */ + return NULL; + } + else + { + /* + The slave does not understand BINLOG_CHECKPOINT_EVENT. Send a dummy + event instead, with same length so slave does not get confused about + binlog positions. + */ + if (Query_log_event::dummy_event(packet, ev_offset, current_checksum_alg)) + return "Failed to replace binlog checkpoint event with dummy: " + "too small event."; + } + } + + /* Skip events with the @@skip_replication flag set, if slave requested skipping of such events. */ |