Description:
When using RBR with the binlog_rows_query_log_events option enabled, SQL
statements are logged in a Rows_query_log_event which is written before the
Table_map_event. Since SQL may contain any binary data including embedded
nulls (\0), it's inappropriate to use null-terminated strings or C string
functions for query strings, and these binary log events are intended to use
the event payload to determine the string length. However, in multiple places
the C strlen() and snprintf() functions are used, causing the query string to
be truncated at the first null byte.
How to repeat:
1. Enable binary logging and binlog_rows_query_log_events.
2. Execute a query containing an embedded null (\0).
3. Observe that the query is truncated in the Rows_query_log_event event.
For example, this can be reproduced based on the following case, creating a test MySQL instance with binlog_rows_query_log_events enabled:
$ dbdeployer deploy single 8.0 --my-cnf-options binlog_rows_query_log_events
A small test program is required to reproduce, because the mysql command doesn't easily allow writing a query with zero bytes in the query string, in this case I used ruby with the mysql2 gem:
$ cat test.rb
#!/usr/bin/env ruby
require "mysql2"
mysql = Mysql2::Client.new(socket: "/tmp/mysql_sandbox8031.sock", username: "msandbox", password: "msandbox")
mysql.query("DROP TABLE IF EXISTS `test`.`t`")
mysql.query("CREATE TABLE `test`.`t` (`name` VARCHAR(255))")
mysql.query("INSERT INTO `test`.`t` (`name`) VALUES (\"foo\0bar\")")
$ ruby test.rb
The truncated query can be seen in the mysqlbinlog output, e.g.:
$ mysqlbinlog -vvv --base64-output=decode-rows binlog.000001
...
# at 8893
#221215 17:53:20 server id 1 end_log_pos 8961 CRC32 0x8a780242 Rows_query
# INSERT INTO `test`.`t` (`name`) VALUES ("foo
# at 8961
#221215 17:53:20 server id 1 end_log_pos 9012 CRC32 0x200b11e6 Table_map: `test`.`t` mapped to number 109
# at 9012
#221215 17:53:20 server id 1 end_log_pos 9057 CRC32 0xd6114e06 Write_rows: table id 109 flags: STMT_END_F
### INSERT INTO `test`.`t`
### SET
### @1='foo\x00bar' /* VARSTRING(1020) meta=1020 nullable=1 is_null=0 */
...
To be sure that it's actually truncated in the binlog rather than just in mysqlbinlog's reading or printing of the query, you can verify with hexdump that the query itself is truncated:
$ hexdump -C binlog.000001
...
000022c0 63 1d 01 00 00 00 44 00 00 00 01 23 00 00 80 00 |c.....D....#....|
000022d0 2c 49 4e 53 45 52 54 20 49 4e 54 4f 20 60 74 65 |,INSERT INTO `te|
000022e0 73 74 60 2e 60 74 60 20 28 60 6e 61 6d 65 60 29 |st`.`t` (`name`)|
000022f0 20 56 41 4c 55 45 53 20 28 22 66 6f 6f 42 02 78 | VALUES ("fooB.x|
00002300 8a 10 5f 9b 63 13 01 00 00 00 33 00 00 00 34 23 |.._.c.....3...4#|
...
Suggested fix:
Audit all usage of Rows_query_log_event::m_rows_query and ensure it is properly handled in all cases and never treated as a null-terminated C string.
Description: When using RBR with the binlog_rows_query_log_events option enabled, SQL statements are logged in a Rows_query_log_event which is written before the Table_map_event. Since SQL may contain any binary data including embedded nulls (\0), it's inappropriate to use null-terminated strings or C string functions for query strings, and these binary log events are intended to use the event payload to determine the string length. However, in multiple places the C strlen() and snprintf() functions are used, causing the query string to be truncated at the first null byte. How to repeat: 1. Enable binary logging and binlog_rows_query_log_events. 2. Execute a query containing an embedded null (\0). 3. Observe that the query is truncated in the Rows_query_log_event event. For example, this can be reproduced based on the following case, creating a test MySQL instance with binlog_rows_query_log_events enabled: $ dbdeployer deploy single 8.0 --my-cnf-options binlog_rows_query_log_events A small test program is required to reproduce, because the mysql command doesn't easily allow writing a query with zero bytes in the query string, in this case I used ruby with the mysql2 gem: $ cat test.rb #!/usr/bin/env ruby require "mysql2" mysql = Mysql2::Client.new(socket: "/tmp/mysql_sandbox8031.sock", username: "msandbox", password: "msandbox") mysql.query("DROP TABLE IF EXISTS `test`.`t`") mysql.query("CREATE TABLE `test`.`t` (`name` VARCHAR(255))") mysql.query("INSERT INTO `test`.`t` (`name`) VALUES (\"foo\0bar\")") $ ruby test.rb The truncated query can be seen in the mysqlbinlog output, e.g.: $ mysqlbinlog -vvv --base64-output=decode-rows binlog.000001 ... # at 8893 #221215 17:53:20 server id 1 end_log_pos 8961 CRC32 0x8a780242 Rows_query # INSERT INTO `test`.`t` (`name`) VALUES ("foo # at 8961 #221215 17:53:20 server id 1 end_log_pos 9012 CRC32 0x200b11e6 Table_map: `test`.`t` mapped to number 109 # at 9012 #221215 17:53:20 server id 1 end_log_pos 9057 CRC32 0xd6114e06 Write_rows: table id 109 flags: STMT_END_F ### INSERT INTO `test`.`t` ### SET ### @1='foo\x00bar' /* VARSTRING(1020) meta=1020 nullable=1 is_null=0 */ ... To be sure that it's actually truncated in the binlog rather than just in mysqlbinlog's reading or printing of the query, you can verify with hexdump that the query itself is truncated: $ hexdump -C binlog.000001 ... 000022c0 63 1d 01 00 00 00 44 00 00 00 01 23 00 00 80 00 |c.....D....#....| 000022d0 2c 49 4e 53 45 52 54 20 49 4e 54 4f 20 60 74 65 |,INSERT INTO `te| 000022e0 73 74 60 2e 60 74 60 20 28 60 6e 61 6d 65 60 29 |st`.`t` (`name`)| 000022f0 20 56 41 4c 55 45 53 20 28 22 66 6f 6f 42 02 78 | VALUES ("fooB.x| 00002300 8a 10 5f 9b 63 13 01 00 00 00 33 00 00 00 34 23 |.._.c.....3...4#| ... Suggested fix: Audit all usage of Rows_query_log_event::m_rows_query and ensure it is properly handled in all cases and never treated as a null-terminated C string.