MySQL Bugs: #112189: Binlog::EventHeader position overflow

Bug #112189	Binlog::EventHeader position overflow
Submitted:	26 Aug 2023 23:41	Modified:	28 Aug 2023 9:57
Reporter:	Marcelo Altmann	Email Updates:
Status:	Verified	Impact on me:	None
Category:	MySQL Server: Replication	Severity:	S3 (Non-critical)
Version:	8.0	OS:	Any
Assigned to:		CPU Architecture:	Any

Description:
Binlog::EventHeader position field is defined as a 4bytes integer:

https://dev.mysql.com/doc/dev/mysql-server/latest/page_protocol_replication_binlog_event.h...

However, binlogs can have more than 4GB in case of a big transaction since they are not rotated in the middle of a transaction, which causes the position to overflow:

# See the end_log_pos after pos 4294967188

# at 4294967134
#230826 14:46:02 server id 1  end_log_pos 4294967188 CRC32 0x29cc2d19 	Table_map: `test`.`big` mapped to number 83
# at 4294967188
#230826 14:46:02 server id 1  end_log_pos 958 CRC32 0xb2b29c19 	Write_rows: table id 83 flags: STMT_END_F
# at 4294968254
#230826 14:46:02 server id 1  end_log_pos 1012 CRC32 0xbbaaa70a 	Table_map: `test`.`big` mapped to number 83
# at 4294968308

How to repeat:

START TRANSACTION;
# 4GB worth of DML
COMMIT;

Suggested fix:
Ideally binlog should report 8 bytes position instead of 4

On another example:

# at 4294966291
#230826 17:11:09 server id 1  end_log_pos 61 CRC32 0x21cf824d 	Write_rows: table id 128 flags: STMT_END_F
# at 4294967357
#230826 17:11:09 server id 1  end_log_pos 115 CRC32 0xfa23cb55 	Table_map: `test`.`big` mapped to number 128

Manually decoding the binlog:
# timestamp
$ xxd -b -s 4294966291 -l4 -c8   /work/ps/ins/8.0/datadir1/binlog.000043
fffffc13: 01011101 01011100 11101010 01100100                                      ]\.d
01100100111010100101110001011101 - 1693080669 - Your time zone: Saturday, August 26, 2023 5:11:09 PM GMT-03:00

# Event type - 30 WRITE_ROWS_EVENT
$ xxd -b -s 4294966295 -l1 -c8   /work/ps/ins/8.0/datadir1/binlog.000043
fffffc17: 00011110

# Server ID - 1
$ xxd -b -s 4294966296 -l4 -c8   /work/ps/ins/8.0/datadir1/binlog.000043
fffffc18: 00000001 00000000 00000000 00000000                                      ....

# Event size - 1066
$ xxd -b -s 4294966300 -l4 -c8   /work/ps/ins/8.0/datadir1/binlog.000043
fffffc1c: 00101010 00000100 00000000 00000000                                      *...

# Pos next Event - 61
$ xxd -b -s 4294966304 -l4 -c8   /work/ps/ins/8.0/datadir1/binlog.000043
fffffc20: 00111101 00000000 00000000 00000000                                      =...

Here is visible that pos next event has overflow. If we get the start pos of this event + Event size we can find the next valid position (4294966291+1066=4294967357)

# Timestamp
$ xxd -b -s 4294967357 -l4 -c8   /work/ps/ins/8.0/datadir1/binlog.000043
10000003d: 01011101 01011100 11101010 01100100                                      ]\.d

We got the same 1693080669 again. So it's visible that the log-pos field of Binlog Event Header can overflow and 4 bytes is not enough.

Hello Marcelo,

Thank you for the report and feedback.

regards,
Umesh