Description:
After turning on log_replica_updates, when the source event is logged to replica binlog, the thread_id is changed.
On 5.7, the thread id is the same after writing down to replica binlog.
After starting replication, if the first event is in row format, the source binlog event's thread_id is replication worker thread's thread_id.
The first query event will replace the work thread's THD's pseudo_thread_id with its own. But the following row format event will always use this thread id until next query event.
Whether this change from 5.7 to 8.0.30 is expected?
How to repeat:
prepare on both source and replica
create database tdb;
use tdb;
create table t1(f1 int, primary key);
reset master on source and build a replication between source and replica, this is for simplify the binlog to check.
on source
=========
session 1
insert into t1 values (1);
session 2
set binlog_format='statement';
insert into t1 values (2);
session 1
insert into t1 values (3);
=========
the result is below
source binlog
#230905 15:34:45 server id 2 end_log_pos 313 CRC32 0xebe0ac22 Query thread_id=12 exec_time=0 error_code=0
SET TIMESTAMP=1693899285/*!*/;
SET @@session.pseudo_thread_id=12/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=0/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8mb4 *//*!*/;
SET @@session.character_set_client=255,@@session.collation_connection=255,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
/*!80011 SET @@session.default_collation_for_utf8mb4=255*//*!*/;
BEGIN
/*!*/;
# at 313
#230905 15:34:45 server id 2 end_log_pos 363 CRC32 0x92cdde48 Table_map: `tdb_pt`.`t1` mapped to number 96
# at 363
#230905 15:34:45 server id 2 end_log_pos 403 CRC32 0x7fce1c41 Write_rows: table id 96 flags: STMT_END_F
BINLOG '
Fdr2ZBMCAAAAMgAAAGsBAAAAAGAAAAAAAAEABnRkYl9wdAACdDEAAQMAAAEBAEjezZI=
Fdr2ZB4CAAAAKAAAAJMBAAAAAGAAAAAAAAEAAgAB/wABAAAAQRzOfw==
'/*!*/;
### INSERT INTO `tdb_pt`.`t1`
### SET
### @1=1 /* INT meta=0 nullable=0 is_null=0 */
# at 403
#230905 15:34:45 server id 2 end_log_pos 434 CRC32 0x0314442e Xid = 39
COMMIT/*!*/;
# at 434
#230905 15:34:51 server id 2 end_log_pos 513 CRC32 0xed6841df GTID last_committed=1 sequence_number=2 rbr_only=no original_committed_timestamp=1693899291661595 immediate_commit_timestamp=1693899291661595 transaction_length=302
# original_commit_timestamp=1693899291661595 (2023-09-05 15:34:51.661595 CST)
# immediate_commit_timestamp=1693899291661595 (2023-09-05 15:34:51.661595 CST)
/*!80001 SET @@session.original_commit_timestamp=1693899291661595*//*!*/;
/*!80014 SET @@session.original_server_version=80030*//*!*/;
/*!80014 SET @@session.immediate_server_version=80030*//*!*/;
SET @@SESSION.GTID_NEXT= 'd5a731cc-08ef-11ee-8a33-525400683dd8:2'/*!*/;
# at 513
#230905 15:34:51 server id 2 end_log_pos 599 CRC32 0x1c7e8d17 Query thread_id=14 exec_time=0 error_code=0
SET TIMESTAMP=1693899291/*!*/;
BEGIN
/*!*/;
# at 599
#230905 15:34:51 server id 2 end_log_pos 705 CRC32 0x6097935c Query thread_id=14 exec_time=0 error_code=0
use `tdb_pt`/*!*/;
SET TIMESTAMP=1693899291/*!*/;
insert into t1 values (2)
/*!*/;
# at 705
#230905 15:34:51 server id 2 end_log_pos 736 CRC32 0x13eabeaf Xid = 41
COMMIT/*!*/;
# at 736
#230905 15:35:00 server id 2 end_log_pos 815 CRC32 0xc425f32e GTID last_committed=2 sequence_number=3 rbr_only=yes original_committed_timestamp=1693899300159944 immediate_commit_timestamp=1693899300159944 transaction_length=277
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
# original_commit_timestamp=1693899300159944 (2023-09-05 15:35:00.159944 CST)
# immediate_commit_timestamp=1693899300159944 (2023-09-05 15:35:00.159944 CST)
/*!80001 SET @@session.original_commit_timestamp=1693899300159944*//*!*/;
/*!80014 SET @@session.original_server_version=80030*//*!*/;
/*!80014 SET @@session.immediate_server_version=80030*//*!*/;
SET @@SESSION.GTID_NEXT= 'd5a731cc-08ef-11ee-8a33-525400683dd8:3'/*!*/;
# at 815
#230905 15:35:00 server id 2 end_log_pos 892 CRC32 0x71011ee8 Query thread_id=12 exec_time=0 error_code=0
SET TIMESTAMP=1693899300/*!*/;
BEGIN
/*!*/;
# at 892
#230905 15:35:00 server id 2 end_log_pos 942 CRC32 0xf94d7d73 Table_map: `tdb_pt`.`t1` mapped to number 96
# at 942
#230905 15:35:00 server id 2 end_log_pos 982 CRC32 0x08b03b0d Write_rows: table id 96 flags: STMT_END_F
BINLOG '
JNr2ZBMCAAAAMgAAAK4DAAAAAGAAAAAAAAEABnRkYl9wdAACdDEAAQMAAAEBAHN9Tfk=
JNr2ZB4CAAAAKAAAANYDAAAAAGAAAAAAAAEAAgAB/wADAAAADTuwCA==
'/*!*/;
### INSERT INTO `tdb_pt`.`t1`
### SET
### @1=3 /* INT meta=0 nullable=0 is_null=0 */
# at 982
#230905 15:35:00 server id 2 end_log_pos 1013 CRC32 0x50285f3b Xid = 42
COMMIT/*!*/;
=======
the replica binlog
#230905 15:34:45 server id 2 end_log_pos 315 CRC32 0x555b1007 Query thread_id=19 exec_time=0 error_code=0
SET TIMESTAMP=1693899285/*!*/;
SET @@session.pseudo_thread_id=19/*!*/;
SET @@session.foreign_key_checks=1, @@session.sql_auto_is_null=0, @@session.unique_checks=1, @@session.autocommit=1/*!*/;
SET @@session.sql_mode=524288/*!*/;
SET @@session.auto_increment_increment=1, @@session.auto_increment_offset=1/*!*/;
/*!\C utf8mb4 *//*!*/;
SET @@session.character_set_client=255,@@session.collation_connection=255,@@session.collation_server=33/*!*/;
SET @@session.lc_time_names=0/*!*/;
SET @@session.collation_database=DEFAULT/*!*/;
/*!80011 SET @@session.default_collation_for_utf8mb4=255*//*!*/;
BEGIN
/*!*/;
# at 315
#230905 15:34:45 server id 2 end_log_pos 365 CRC32 0xb8a4cad0 Table_map: `tdb_pt`.`t1` mapped to number 94
# at 365
#230905 15:34:45 server id 2 end_log_pos 405 CRC32 0xead23d2a Write_rows: table id 94 flags: STMT_END_F
BINLOG '
Fdr2ZBMCAAAAMgAAAG0BAAAAAF4AAAAAAAEABnRkYl9wdAACdDEAAQMAAAEBANDKpLg=
Fdr2ZB4CAAAAKAAAAJUBAAAAAF4AAAAAAAEAAgAB/wABAAAAKj3S6g==
'/*!*/;
### INSERT INTO `tdb_pt`.`t1`
### SET
### @1=1 /* INT meta=0 nullable=0 is_null=0 */
# at 405
#230905 15:34:45 server id 2 end_log_pos 436 CRC32 0x550f7881 Xid = 11
COMMIT/*!*/;
# at 436
#230905 15:34:51 server id 2 end_log_pos 522 CRC32 0xc5b8886a GTID last_committed=1 sequence_number=2 rbr_only=yes original_committed_timestamp=1693899291661595 immediate_commit_timestamp=1693899291666121 transaction_length=284
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
# original_commit_timestamp=1693899291661595 (2023-09-05 15:34:51.661595 CST)
# immediate_commit_timestamp=1693899291666121 (2023-09-05 15:34:51.666121 CST)
/*!80001 SET @@session.original_commit_timestamp=1693899291661595*//*!*/;
/*!80014 SET @@session.original_server_version=80030*//*!*/;
/*!80014 SET @@session.immediate_server_version=80030*//*!*/;
SET @@SESSION.GTID_NEXT= 'd5a731cc-08ef-11ee-8a33-525400683dd8:2'/*!*/;
# at 522
#230905 15:34:51 server id 2 end_log_pos 599 CRC32 0xb4786c88 Query thread_id=14 exec_time=0 error_code=0
SET TIMESTAMP=1693899291/*!*/;
SET @@session.sql_mode=0/*!*/;
BEGIN
/*!*/;
# at 599
#230905 15:34:51 server id 2 end_log_pos 649 CRC32 0xf8df0f28 Table_map: `tdb_pt`.`t1` mapped to number 94
# at 649
#230905 15:34:51 server id 2 end_log_pos 689 CRC32 0x7ac6d45d Write_rows: table id 94 flags: STMT_END_F
BINLOG '
G9r2ZBMCAAAAMgAAAIkCAAAAAF4AAAAAAAEABnRkYl9wdAACdDEAAQMAAAEBACgP3/g=
G9r2ZB4CAAAAKAAAALECAAAAAF4AAAAAAAEAAgAB/wACAAAAXdTGeg==
'/*!*/;
### INSERT INTO `tdb_pt`.`t1`
### SET
### @1=2 /* INT meta=0 nullable=0 is_null=0 */
# at 689
#230905 15:34:51 server id 2 end_log_pos 720 CRC32 0xc50096b7 Xid = 13
COMMIT/*!*/;
# at 720
#230905 15:35:00 server id 2 end_log_pos 806 CRC32 0xe9187e79 GTID last_committed=2 sequence_number=3 rbr_only=yes original_committed_timestamp=1693899300159944 immediate_commit_timestamp=1693899300163501 transaction_length=279
/*!50718 SET TRANSACTION ISOLATION LEVEL READ COMMITTED*//*!*/;
# original_commit_timestamp=1693899300159944 (2023-09-05 15:35:00.159944 CST)
# immediate_commit_timestamp=1693899300163501 (2023-09-05 15:35:00.163501 CST)
/*!80001 SET @@session.original_commit_timestamp=1693899300159944*//*!*/;
/*!80014 SET @@session.original_server_version=80030*//*!*/;
/*!80014 SET @@session.immediate_server_version=80030*//*!*/;
SET @@SESSION.GTID_NEXT= 'd5a731cc-08ef-11ee-8a33-525400683dd8:3'/*!*/;
# at 806
#230905 15:35:00 server id 2 end_log_pos 878 CRC32 0x2b6eff86 Query thread_id=14 exec_time=0 error_code=0
SET TIMESTAMP=1693899300/*!*/;
SET @@session.sql_mode=524288/*!*/;
BEGIN
/*!*/;
# at 878
#230905 15:35:00 server id 2 end_log_pos 928 CRC32 0xbfc1e832 Table_map: `tdb_pt`.`t1` mapped to number 94
# at 928
#230905 15:35:00 server id 2 end_log_pos 968 CRC32 0x9c67df0c Write_rows: table id 94 flags: STMT_END_F
BINLOG '
JNr2ZBMCAAAAMgAAAKADAAAAAF4AAAAAAAEABnRkYl9wdAACdDEAAQMAAAEBADLowb8=
JNr2ZB4CAAAAKAAAAMgDAAAAAF4AAAAAAAEAAgAB/wADAAAADN9nnA==
'/*!*/;
### INSERT INTO `tdb_pt`.`t1`
### SET
### @1=3 /* INT meta=0 nullable=0 is_null=0 */
# at 968
#230905 15:35:00 server id 2 end_log_pos 999 CRC32 0x6662cbc8 Xid = 15
COMMIT/*!*/;
Suggested fix:
--- a/sql/log_event.cc
+++ b/sql/log_event.cc
@@ -5110,7 +5110,6 @@ int Query_log_event::do_apply_event(Relay_log_info const *rli,
thd->rpl_thd_ctx.post_filters_actions().push_back(f);
}
- thd->variables.pseudo_thread_id = thread_id;
thd->set_time(&(common_header->when));
thd->set_query(query_arg, q_len_arg);
thd->set_query_for_display(query_arg, q_len_arg);