Details
-
Bug
-
Status: Closed (View Workflow)
-
Major
-
Resolution: Fixed
-
10.1(EOL), 10.2(EOL), 10.3(EOL), 10.4(EOL)
Description
SHOW BINLOG EVENTS FROM <pos> causes a variety of failures, some of which are listed below. It is not a race condition issue, but there is some non-determinism in it, I can't figure the cause of it.
The following test case is a bit ugly, but it is a self-contained proof of concept, it shows that the failures happen without any tampering with the binary log:
--source include/have_log_bin.inc
|
--source include/have_binlog_format_mixed.inc
|
--source include/have_innodb.inc
|
DROP TABLE /*! IF EXISTS*/ t1; |
CREATE TABLE `t1` ( |
`col_int` int, |
pk integer auto_increment, |
`col_char_12_key` char(12), |
`col_int_key` int, |
`col_char_12` char(12), |
primary key (pk), |
key (`col_char_12_key` ), |
key (`col_int_key` )) ENGINE=InnoDB; |
INSERT /*! IGNORE */ INTO t1 VALUES (183173120, NULL, 'abcd', 1, 'efghijk'), (1, NULL, 'lmno', 2, 'p'); |
ALTER TABLE `t1` ENABLE KEYS; |
--let $max_pos= query_get_value(SHOW MASTER STATUS,Position,1)
|
--let $pos= 1
|
while ($pos <= $max_pos)
|
{
|
--error 0,1220 |
eval SHOW BINLOG EVENTS FROM $pos; |
--inc $pos |
}
|
|
10.1 ASAN 1b471face8 |
=================================================================
|
==15715==ERROR: AddressSanitizer: unknown-crash on address 0x61200019074b at pc 0x55abe4db87f7 bp 0x7ffa25838fc0 sp 0x7ffa25838fb8
|
READ of size 511 at 0x61200019074b thread T28
|
#0 0x55abe4db87f6 in my_strndup /data/src/10.2/mysys/my_malloc.c:253
|
#1 0x55abe4032bbe in Rotate_log_event::Rotate_log_event(char const*, unsigned int, Format_description_log_event const*) /data/src/10.2/sql/log_event.cc:7239
|
#2 0x55abe40166d8 in Log_event::read_log_event(char const*, unsigned int, char const**, Format_description_log_event const*, char) /data/src/10.2/sql/log_event.cc:2094
|
#3 0x55abe4015929 in Log_event::read_log_event(st_io_cache*, st_mysql_mutex*, Format_description_log_event const*, char) /data/src/10.2/sql/log_event.cc:1923
|
#4 0x55abe3800fe2 in mysql_show_binlog_events(THD*) /data/src/10.2/sql/sql_repl.cc:3965
|
#5 0x55abe377686c in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:3598
|
#6 0x55abe3792125 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.2/sql/sql_parse.cc:8014
|
#7 0x55abe376cb0f in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1825
|
#8 0x55abe3769bb3 in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1379
|
#9 0x55abe3aaf558 in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1335
|
#10 0x55abe3aaef6d in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241
|
#11 0x55abe44c9f9d in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1862
|
#12 0x7ffa36053493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
|
#13 0x7ffa3465493e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe893e)
|
|
|
0x6120001907cc is located 0 bytes to the right of 268-byte region [0x6120001906c0,0x6120001907cc)
|
allocated by thread T28 here:
|
#0 0x7ffa362bd73f in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x5473f)
|
#1 0x55abe4de85b9 in sf_malloc /data/src/10.2/mysys/safemalloc.c:118
|
#2 0x55abe4db7810 in my_malloc /data/src/10.2/mysys/my_malloc.c:101
|
#3 0x55abe394e199 in String::realloc_raw(unsigned long) /data/src/10.2/sql/sql_string.cc:102
|
#4 0x55abe35aab08 in String::realloc_with_extra(unsigned long) /data/src/10.2/sql/sql_string.h:376
|
#5 0x55abe3955048 in String::realloc_with_extra_if_needed(unsigned long) /data/src/10.2/sql/sql_string.h:388
|
#6 0x55abe3950ace in String::append(char const*, unsigned long) /data/src/10.2/sql/sql_string.cc:499
|
#7 0x55abe4014bf4 in Log_event::read_log_event(st_io_cache*, String*, Format_description_log_event const*, enum_binlog_checksum_alg) /data/src/10.2/sql/log_event.cc:1795
|
#8 0x55abe401581e in Log_event::read_log_event(st_io_cache*, st_mysql_mutex*, Format_description_log_event const*, char) /data/src/10.2/sql/log_event.cc:1892
|
#9 0x55abe3800fe2 in mysql_show_binlog_events(THD*) /data/src/10.2/sql/sql_repl.cc:3965
|
#10 0x55abe377686c in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:3598
|
#11 0x55abe3792125 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.2/sql/sql_parse.cc:8014
|
#12 0x55abe376cb0f in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1825
|
#13 0x55abe3769bb3 in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1379
|
#14 0x55abe3aaf558 in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1335
|
#15 0x55abe3aaef6d in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241
|
#16 0x55abe44c9f9d in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1862
|
#17 0x7ffa36053493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493)
|
|
|
Thread T28 created by T0 here:
|
#0 0x7ffa3628cbba in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x23bba)
|
#1 0x55abe44ca565 in spawn_thread_v1 /data/src/10.2/storage/perfschema/pfs.cc:1912
|
#2 0x55abe356650e in inline_mysql_thread_create /data/src/10.2/include/mysql/psi/mysql_thread.h:1239
|
#3 0x55abe357b4ab in create_thread_to_handle_connection(CONNECT*) /data/src/10.2/sql/mysqld.cc:6466
|
#4 0x55abe357bbb0 in create_new_thread /data/src/10.2/sql/mysqld.cc:6536
|
#5 0x55abe357cbc7 in handle_connections_sockets() /data/src/10.2/sql/mysqld.cc:6811
|
#6 0x55abe357aa00 in mysqld_main(int, char**) /data/src/10.2/sql/mysqld.cc:6085
|
#7 0x55abe35648af in main /data/src/10.2/sql/main.cc:25
|
#8 0x7ffa3458c2b0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202b0)
|
|
|
SUMMARY: AddressSanitizer: unknown-crash /data/src/10.2/mysys/my_malloc.c:253 my_strndup
|
Shadow bytes around the buggy address:
|
0x0c248002a090: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
|
0x0c248002a0a0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
|
0x0c248002a0b0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
|
0x0c248002a0c0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa
|
0x0c248002a0d0: fa fa fa fa fa fa fa fa 00 00 00 00 00 00 00 00
|
=>0x0c248002a0e0: 00 00 00 00 00 00 00 00 00[00]00 00 00 00 00 00
|
0x0c248002a0f0: 00 00 00 00 00 00 00 00 00 04 fa fa fa fa fa fa
|
0x0c248002a100: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
|
0x0c248002a110: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
|
0x0c248002a120: fd fd fd fd fd fd fd fd fd fd fa fa fa fa fa fa
|
0x0c248002a130: fa fa fa fa fa fa fa fa 00 00 00 00 00 00 00 00
|
Shadow byte legend (one shadow byte represents 8 application bytes):
|
Addressable: 00
|
Partially addressable: 01 02 03 04 05 06 07
|
Heap left redzone: fa
|
Heap right redzone: fb
|
Freed heap region: fd
|
Stack left redzone: f1
|
Stack mid redzone: f2
|
Stack right redzone: f3
|
Stack partial redzone: f4
|
Stack after return: f5
|
Stack use after scope: f8
|
Global redzone: f9
|
Global init order: f6
|
Poisoned by user: f7
|
Contiguous container OOB:fc
|
ASan internal: fe
|
==15715==ABORTING
|
However, since the whole thing is rather unreliable, it might happen that it's not reproducible on a different machine.
A wider variety of problems can be observed while running SHOW BINLOG EVENTS FROM ... with different positions on the attached mysql-bin.000001
. The log was produced by MariaDB 10.4, so start 10.4 server with all defaults and log-bin=mysql-bin.000001 with the attached log in the datadir, and run SHOW BINLOG EVENTS FROM ... with various positions.
I've got the following for the first 8000 positions (didn't go further):
SHOW BINLOG EVENTS FROM 365; |
-- or
|
SHOW BINLOG EVENTS FROM 491; |
-- or
|
SHOW BINLOG EVENTS FROM 2327; |
-- or
|
SHOW BINLOG EVENTS FROM 4264; |
|
10.4 30641f9df77 |
mysqld: /data/src/10.4/sql/log_event.cc:10863: Rows_log_event::Rows_log_event(const char*, uint, const Format_description_log_event*): Assertion `var_header_len >= 2' failed.
|
181220 15:27:02 [ERROR] mysqld got signal 6 ;
|
|
|
#7 0x00007fa0d96abee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
|
#8 0x000055e744ef82de in Rows_log_event::Rows_log_event (this=0x7fa05800d390, buf=0x7fa05800d080 "", event_len=254, description_event=0x7fa058006d60) at /data/src/10.4/sql/log_event.cc:10863
|
#9 0x000055e744f00cf8 in Update_rows_log_event::Update_rows_log_event (this=0x7fa05800d390, buf=0x7fa05800d080 "", event_len=254, description_event=0x7fa058006d60) at /data/src/10.4/sql/log_event.cc:14240
|
#10 0x000055e744ee5fb3 in Log_event::read_log_event (buf=0x7fa05800d080 "", event_len=254, error=0x7fa0d8134550, fdle=0x7fa058006d60, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:2168
|
#11 0x000055e744ee55fb in Log_event::read_log_event (file=0x7fa0d81346b0, fdle=0x7fa058006d60, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:1939
|
#12 0x000055e744ad9d55 in mysql_show_binlog_events (thd=0x7fa058000b00) at /data/src/10.4/sql/sql_repl.cc:4004
|
#13 0x000055e744a9d505 in mysql_execute_command (thd=0x7fa058000b00) at /data/src/10.4/sql/sql_parse.cc:3887
|
#14 0x000055e744aaa8e4 in mysql_parse (thd=0x7fa058000b00, rawbuf=0x7fa058013be8 "SHOW BINLOG EVENTS FROM 365", length=27, parser_state=0x7fa0d8135650, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8104
|
#15 0x000055e744a97b0e in dispatch_command (command=COM_QUERY, thd=0x7fa058000b00, packet=0x7fa05801be11 "", packet_length=27, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1851
|
#16 0x000055e744a96532 in do_command (thd=0x7fa058000b00) at /data/src/10.4/sql/sql_parse.cc:1396
|
#17 0x000055e744c026de in do_handle_one_connection (connect=0x55e748a968b0) at /data/src/10.4/sql/sql_connect.cc:1402
|
#18 0x000055e744c02462 in handle_one_connection (arg=0x55e748a968b0) at /data/src/10.4/sql/sql_connect.cc:1308
|
#19 0x00007fa0db167494 in start_thread (arg=0x7fa0d8136700) at pthread_create.c:333
|
#20 0x00007fa0d976893f in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
SHOW BINLOG EVENTS FROM 1366; |
-- or
|
SHOW BINLOG EVENTS FROM 3576; |
-- or
|
SHOW BINLOG EVENTS FROM 4380; |
-- or
|
SHOW BINLOG EVENTS FROM 4394; |
-- or
|
SHOW BINLOG EVENTS FROM 7992; |
|
10.4 30641f9df77 |
mysqld: /data/src/10.4/sql/log_event.cc:1055: uint32 binlog_get_uncompress_len(const char*): Assertion `(buf[0] & 0xe0) == 0x80' failed.
|
181220 15:33:56 [ERROR] mysqld got signal 6 ;
|
|
|
#7 0x00007f77fd57aee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
|
#8 0x0000559995bf8f32 in binlog_get_uncompress_len (buf=0x7f779000d560 "") at /data/src/10.4/sql/log_event.cc:1055
|
#9 0x0000559995c0ea9f in Rows_log_event::uncompress_buf (this=0x7f779000d390) at /data/src/10.4/sql/log_event.cc:10990
|
#10 0x0000559995c1395d in Write_rows_compressed_log_event::Write_rows_compressed_log_event (this=0x7f779000d390, buf=0x7f779000d080 "", event_len=254, description_event=0x7f7790006cd0) at /data/src/10.4/sql/log_event.cc:12897
|
#11 0x0000559995bfc00b in Log_event::read_log_event (buf=0x7f779000d080 "", event_len=254, error=0x7f77e5d80550, fdle=0x7f7790006cd0, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:2177
|
#12 0x0000559995bfb5fb in Log_event::read_log_event (file=0x7f77e5d806b0, fdle=0x7f7790006cd0, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:1939
|
#13 0x00005599957efd55 in mysql_show_binlog_events (thd=0x7f7790000b00) at /data/src/10.4/sql/sql_repl.cc:4004
|
#14 0x00005599957b3505 in mysql_execute_command (thd=0x7f7790000b00) at /data/src/10.4/sql/sql_parse.cc:3887
|
#15 0x00005599957c08e4 in mysql_parse (thd=0x7f7790000b00, rawbuf=0x7f7790013be8 "SHOW BINLOG EVENTS FROM 1366", length=28, parser_state=0x7f77e5d81650, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8104
|
#16 0x00005599957adb0e in dispatch_command (command=COM_QUERY, thd=0x7f7790000b00, packet=0x7f779001be11 "", packet_length=28, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1851
|
#17 0x00005599957ac532 in do_command (thd=0x7f7790000b00) at /data/src/10.4/sql/sql_parse.cc:1396
|
#18 0x00005599959186de in do_handle_one_connection (connect=0x559999441700) at /data/src/10.4/sql/sql_connect.cc:1402
|
#19 0x0000559995918462 in handle_one_connection (arg=0x559999441700) at /data/src/10.4/sql/sql_connect.cc:1308
|
#20 0x00007f77ff036494 in start_thread (arg=0x7f77e5d82700) at pthread_create.c:333
|
#21 0x00007f77fd63793f in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
SHOW BINLOG EVENTS FROM 3876; |
|
10.4 30641f9df77 |
mysqld: /data/src/10.4/sql/log_event.cc:12376: Table_map_log_event::Table_map_log_event(const char*, uint, const Format_description_log_event*): Assertion `m_field_metadata_size <= (m_colcnt * 2)' failed.
|
181220 15:36:33 [ERROR] mysqld got signal 6 ;
|
|
|
#7 0x00007f611f6c6ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6
|
#8 0x0000560a9e1cd75b in Table_map_log_event::Table_map_log_event (this=0x7f60a8013a50, buf=0x7f60a800d080 "", event_len=254, description_event=0x7f60a8006cd0) at /data/src/10.4/sql/log_event.cc:12376
|
#9 0x0000560a9e1b70c8 in Log_event::read_log_event (buf=0x7f60a800d080 "", event_len=254, error=0x7f611c1f4550, fdle=0x7f60a8006cd0, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:2200
|
#10 0x0000560a9e1b65fb in Log_event::read_log_event (file=0x7f611c1f46b0, fdle=0x7f60a8006cd0, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:1939
|
#11 0x0000560a9ddaad55 in mysql_show_binlog_events (thd=0x7f60a8000b00) at /data/src/10.4/sql/sql_repl.cc:4004
|
#12 0x0000560a9dd6e505 in mysql_execute_command (thd=0x7f60a8000b00) at /data/src/10.4/sql/sql_parse.cc:3887
|
#13 0x0000560a9dd7b8e4 in mysql_parse (thd=0x7f60a8000b00, rawbuf=0x7f60a8013be8 "SHOW BINLOG EVENTS FROM 3876", length=28, parser_state=0x7f611c1f5650, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8104
|
#14 0x0000560a9dd68b0e in dispatch_command (command=COM_QUERY, thd=0x7f60a8000b00, packet=0x7f60a801be11 "", packet_length=28, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1851
|
#15 0x0000560a9dd67532 in do_command (thd=0x7f60a8000b00) at /data/src/10.4/sql/sql_parse.cc:1396
|
#16 0x0000560a9ded36de in do_handle_one_connection (connect=0x560aa0b1c700) at /data/src/10.4/sql/sql_connect.cc:1402
|
#17 0x0000560a9ded3462 in handle_one_connection (arg=0x560aa0b1c700) at /data/src/10.4/sql/sql_connect.cc:1308
|
#18 0x00007f6121182494 in start_thread (arg=0x7f611c1f6700) at pthread_create.c:333
|
#19 0x00007f611f78393f in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
SHOW BINLOG EVENTS FROM 6191; |
-- or
|
SHOW BINLOG EVENTS FROM 6367; |
-- or
|
SHOW BINLOG EVENTS FROM 7951; |
|
10.4 30641f9df77 |
181220 15:29:56 [ERROR] mysqld got signal 11 ;
|
|
|
#3 <signal handler called>
|
#4 0x0000556cb316374b in inline_mysql_mutex_destroy (that=0xa5a5a5a5a5a5a5a5, src_file=0x556cb35eb5e8 "/data/src/10.4/mysys/my_bitmap.c", src_line=214) at /data/src/10.4/include/mysql/psi/mysql_thread.h:662
|
#5 0x0000556cb3163f25 in my_bitmap_free (map=0x7fbc1811bb90) at /data/src/10.4/mysys/my_bitmap.c:214
|
#6 0x0000556cb2b11c76 in Update_rows_log_event::~Update_rows_log_event (this=0x7fbc1811baf0, __in_chrg=<optimized out>) at /data/src/10.4/sql/log_event.cc:14228
|
#7 0x0000556cb2b11cb6 in Update_rows_log_event::~Update_rows_log_event (this=0x7fbc1811baf0, __in_chrg=<optimized out>) at /data/src/10.4/sql/log_event.cc:14229
|
#8 0x0000556cb2af7332 in Log_event::read_log_event (buf=0x7fbc180e30f0 "", event_len=27, error=0x7fbc8c2c7550, fdle=0x7fbc1811b970, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:2267
|
#9 0x0000556cb2af65fb in Log_event::read_log_event (file=0x7fbc8c2c76b0, fdle=0x7fbc1811b970, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:1939
|
#10 0x0000556cb26ead55 in mysql_show_binlog_events (thd=0x7fbc18000b00) at /data/src/10.4/sql/sql_repl.cc:4004
|
#11 0x0000556cb26ae505 in mysql_execute_command (thd=0x7fbc18000b00) at /data/src/10.4/sql/sql_parse.cc:3887
|
#12 0x0000556cb26bb8e4 in mysql_parse (thd=0x7fbc18000b00, rawbuf=0x7fbc18013be8 "SHOW BINLOG EVENTS FROM 7951", length=28, parser_state=0x7fbc8c2c8650, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8104
|
#13 0x0000556cb26a8b0e in dispatch_command (command=COM_QUERY, thd=0x7fbc18000b00, packet=0x7fbc1801be11 "", packet_length=28, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1851
|
#14 0x0000556cb26a7532 in do_command (thd=0x7fbc18000b00) at /data/src/10.4/sql/sql_parse.cc:1396
|
#15 0x0000556cb28136de in do_handle_one_connection (connect=0x556cb67b0700) at /data/src/10.4/sql/sql_connect.cc:1402
|
#16 0x0000556cb2813462 in handle_one_connection (arg=0x556cb67b0700) at /data/src/10.4/sql/sql_connect.cc:1308
|
#17 0x00007fbc90a54494 in start_thread (arg=0x7fbc8c2c9700) at pthread_create.c:333
|
#18 0x00007fbc8f05593f in clone () from /lib/x86_64-linux-gnu/libc.so.6
|
For the record, this is the basic concurrent test that I ran (not sure if it can reproduce all the above failures, but it can surely reproduce some):
|
https://github.com/MariaDB/randgen elenst-dev 89b8fe94565 |
perl ./runall-new.pl --basedir=/home/travis/server/10.4 --duration=350 --threads=2 --mysqld=--log_output=FILE --mysqld=--loose-max-statement-time=5 --mysqld=--lock-wait-timeout=2 --mysqld=--loose-innodb-lock-wait-timeout=1 --mysqld=--loose-debug_assert_on_not_freed_memory=0 --grammar=binevent.yy --gendata=conf/engines/engine_stress.zz --mysqld=--log_bin_trust_function_creators=1 --mysqld=--log-bin --vardir=/home/travis/logs/vardir
|
The grammar is attached. It's very big and probably essentially excessive, but I don't expect it to be needed anyway, probably the binlog will be much easier to analyze.
Attachments
Activity
| Field | Original Value | New Value |
|---|---|---|
| Assignee | Elena Stepanova [ elenst ] | Andrei Elkin [ elkin ] |
| Description |
{{SHOW BINLOG EVENTS FROM <pos>}} causes a variety of failures, some of which are listed below. It is not a race condition issue, but there is some non-determinism in it, I can't figure the cause of it.
The following test case is a bit ugly, but it is a self-contained proof of concept, it shows that the failures happen without any tampering with the binary log: {code:sql} --source include/have_log_bin.inc --source include/have_binlog_format_mixed.inc --source include/have_innodb.inc DROP TABLE /*! IF EXISTS*/ t1; CREATE TABLE `t1` ( `col_int` int, pk integer auto_increment, `col_char_12_key` char(12), `col_int_key` int, `col_char_12` char(12), primary key (pk), key (`col_char_12_key` ), key (`col_int_key` )) ENGINE=InnoDB; INSERT /*! IGNORE */ INTO t1 VALUES (183173120, NULL, 'abcd', 1, 'efghijk'), (1, NULL, 'lmno', 2, 'p'); ALTER TABLE `t1` ENABLE KEYS; --let $max_pos= query_get_value(SHOW MASTER STATUS,Position,1) --let $pos= 1 while ($pos <= $max_pos) { --error 0,1220 eval SHOW BINLOG EVENTS FROM $pos; --inc $pos } {code} {noformat:title=10.1 ASAN 1b471face8} ================================================================= ==15715==ERROR: AddressSanitizer: unknown-crash on address 0x61200019074b at pc 0x55abe4db87f7 bp 0x7ffa25838fc0 sp 0x7ffa25838fb8 READ of size 511 at 0x61200019074b thread T28 #0 0x55abe4db87f6 in my_strndup /data/src/10.2/mysys/my_malloc.c:253 #1 0x55abe4032bbe in Rotate_log_event::Rotate_log_event(char const*, unsigned int, Format_description_log_event const*) /data/src/10.2/sql/log_event.cc:7239 #2 0x55abe40166d8 in Log_event::read_log_event(char const*, unsigned int, char const**, Format_description_log_event const*, char) /data/src/10.2/sql/log_event.cc:2094 #3 0x55abe4015929 in Log_event::read_log_event(st_io_cache*, st_mysql_mutex*, Format_description_log_event const*, char) /data/src/10.2/sql/log_event.cc:1923 #4 0x55abe3800fe2 in mysql_show_binlog_events(THD*) /data/src/10.2/sql/sql_repl.cc:3965 #5 0x55abe377686c in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:3598 #6 0x55abe3792125 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.2/sql/sql_parse.cc:8014 #7 0x55abe376cb0f in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1825 #8 0x55abe3769bb3 in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1379 #9 0x55abe3aaf558 in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1335 #10 0x55abe3aaef6d in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241 #11 0x55abe44c9f9d in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1862 #12 0x7ffa36053493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493) #13 0x7ffa3465493e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe893e) 0x6120001907cc is located 0 bytes to the right of 268-byte region [0x6120001906c0,0x6120001907cc) allocated by thread T28 here: #0 0x7ffa362bd73f in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x5473f) #1 0x55abe4de85b9 in sf_malloc /data/src/10.2/mysys/safemalloc.c:118 #2 0x55abe4db7810 in my_malloc /data/src/10.2/mysys/my_malloc.c:101 #3 0x55abe394e199 in String::realloc_raw(unsigned long) /data/src/10.2/sql/sql_string.cc:102 #4 0x55abe35aab08 in String::realloc_with_extra(unsigned long) /data/src/10.2/sql/sql_string.h:376 #5 0x55abe3955048 in String::realloc_with_extra_if_needed(unsigned long) /data/src/10.2/sql/sql_string.h:388 #6 0x55abe3950ace in String::append(char const*, unsigned long) /data/src/10.2/sql/sql_string.cc:499 #7 0x55abe4014bf4 in Log_event::read_log_event(st_io_cache*, String*, Format_description_log_event const*, enum_binlog_checksum_alg) /data/src/10.2/sql/log_event.cc:1795 #8 0x55abe401581e in Log_event::read_log_event(st_io_cache*, st_mysql_mutex*, Format_description_log_event const*, char) /data/src/10.2/sql/log_event.cc:1892 #9 0x55abe3800fe2 in mysql_show_binlog_events(THD*) /data/src/10.2/sql/sql_repl.cc:3965 #10 0x55abe377686c in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:3598 #11 0x55abe3792125 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.2/sql/sql_parse.cc:8014 #12 0x55abe376cb0f in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1825 #13 0x55abe3769bb3 in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1379 #14 0x55abe3aaf558 in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1335 #15 0x55abe3aaef6d in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241 #16 0x55abe44c9f9d in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1862 #17 0x7ffa36053493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493) Thread T28 created by T0 here: #0 0x7ffa3628cbba in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x23bba) #1 0x55abe44ca565 in spawn_thread_v1 /data/src/10.2/storage/perfschema/pfs.cc:1912 #2 0x55abe356650e in inline_mysql_thread_create /data/src/10.2/include/mysql/psi/mysql_thread.h:1239 #3 0x55abe357b4ab in create_thread_to_handle_connection(CONNECT*) /data/src/10.2/sql/mysqld.cc:6466 #4 0x55abe357bbb0 in create_new_thread /data/src/10.2/sql/mysqld.cc:6536 #5 0x55abe357cbc7 in handle_connections_sockets() /data/src/10.2/sql/mysqld.cc:6811 #6 0x55abe357aa00 in mysqld_main(int, char**) /data/src/10.2/sql/mysqld.cc:6085 #7 0x55abe35648af in main /data/src/10.2/sql/main.cc:25 #8 0x7ffa3458c2b0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202b0) SUMMARY: AddressSanitizer: unknown-crash /data/src/10.2/mysys/my_malloc.c:253 my_strndup Shadow bytes around the buggy address: 0x0c248002a090: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c248002a0a0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c248002a0b0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c248002a0c0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c248002a0d0: fa fa fa fa fa fa fa fa 00 00 00 00 00 00 00 00 =>0x0c248002a0e0: 00 00 00 00 00 00 00 00 00[00]00 00 00 00 00 00 0x0c248002a0f0: 00 00 00 00 00 00 00 00 00 04 fa fa fa fa fa fa 0x0c248002a100: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd 0x0c248002a110: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd 0x0c248002a120: fd fd fd fd fd fd fd fd fd fd fa fa fa fa fa fa 0x0c248002a130: fa fa fa fa fa fa fa fa 00 00 00 00 00 00 00 00 Shadow byte legend (one shadow byte represents 8 application bytes): Addressable: 00 Partially addressable: 01 02 03 04 05 06 07 Heap left redzone: fa Heap right redzone: fb Freed heap region: fd Stack left redzone: f1 Stack mid redzone: f2 Stack right redzone: f3 Stack partial redzone: f4 Stack after return: f5 Stack use after scope: f8 Global redzone: f9 Global init order: f6 Poisoned by user: f7 Contiguous container OOB:fc ASan internal: fe ==15715==ABORTING {noformat} However, since the whole thing is rather unreliable, it might happen that it's not reproducible on a different machine. A wider variety of problems can be observed while running {{SHOW BINLOG EVENTS FROM ...}} with different positions on the attached [^mysql-bin.000001]. The log was produced by MariaDB 10.4, so start 10.4 server with all defaults and {{log-bin=mysql-bin.000001}} with the attached log in the datadir, and run {{SHOW BINLOG EVENTS FROM ...}} with various positions. I've got the following for the first 8000 positions (didn't go further): {code:sql} SHOW BINLOG EVENTS FROM 365; -- or SHOW BINLOG EVENTS FROM 491; -- or SHOW BINLOG EVENTS FROM 2327; -- or SHOW BINLOG EVENTS FROM 4264; {code} {noformat:title=10.4 30641f9df77} mysqld: /data/src/10.4/sql/log_event.cc:10863: Rows_log_event::Rows_log_event(const char*, uint, const Format_description_log_event*): Assertion `var_header_len >= 2' failed. 181220 15:27:02 [ERROR] mysqld got signal 6 ; #7 0x00007fa0d96abee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6 #8 0x000055e744ef82de in Rows_log_event::Rows_log_event (this=0x7fa05800d390, buf=0x7fa05800d080 "", event_len=254, description_event=0x7fa058006d60) at /data/src/10.4/sql/log_event.cc:10863 #9 0x000055e744f00cf8 in Update_rows_log_event::Update_rows_log_event (this=0x7fa05800d390, buf=0x7fa05800d080 "", event_len=254, description_event=0x7fa058006d60) at /data/src/10.4/sql/log_event.cc:14240 #10 0x000055e744ee5fb3 in Log_event::read_log_event (buf=0x7fa05800d080 "", event_len=254, error=0x7fa0d8134550, fdle=0x7fa058006d60, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:2168 #11 0x000055e744ee55fb in Log_event::read_log_event (file=0x7fa0d81346b0, fdle=0x7fa058006d60, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:1939 #12 0x000055e744ad9d55 in mysql_show_binlog_events (thd=0x7fa058000b00) at /data/src/10.4/sql/sql_repl.cc:4004 #13 0x000055e744a9d505 in mysql_execute_command (thd=0x7fa058000b00) at /data/src/10.4/sql/sql_parse.cc:3887 #14 0x000055e744aaa8e4 in mysql_parse (thd=0x7fa058000b00, rawbuf=0x7fa058013be8 "SHOW BINLOG EVENTS FROM 365", length=27, parser_state=0x7fa0d8135650, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8104 #15 0x000055e744a97b0e in dispatch_command (command=COM_QUERY, thd=0x7fa058000b00, packet=0x7fa05801be11 "", packet_length=27, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1851 #16 0x000055e744a96532 in do_command (thd=0x7fa058000b00) at /data/src/10.4/sql/sql_parse.cc:1396 #17 0x000055e744c026de in do_handle_one_connection (connect=0x55e748a968b0) at /data/src/10.4/sql/sql_connect.cc:1402 #18 0x000055e744c02462 in handle_one_connection (arg=0x55e748a968b0) at /data/src/10.4/sql/sql_connect.cc:1308 #19 0x00007fa0db167494 in start_thread (arg=0x7fa0d8136700) at pthread_create.c:333 #20 0x00007fa0d976893f in clone () from /lib/x86_64-linux-gnu/libc.so.6 {noformat} {code:sql} SHOW BINLOG EVENTS FROM 1366; -- or SHOW BINLOG EVENTS FROM 3576; -- or SHOW BINLOG EVENTS FROM 4380; -- or SHOW BINLOG EVENTS FROM 4394; -- or SHOW BINLOG EVENTS FROM 7992; {code} {noformat:title=10.4 30641f9df77} mysqld: /data/src/10.4/sql/log_event.cc:1055: uint32 binlog_get_uncompress_len(const char*): Assertion `(buf[0] & 0xe0) == 0x80' failed. 181220 15:33:56 [ERROR] mysqld got signal 6 ; #7 0x00007f77fd57aee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6 #8 0x0000559995bf8f32 in binlog_get_uncompress_len (buf=0x7f779000d560 "") at /data/src/10.4/sql/log_event.cc:1055 #9 0x0000559995c0ea9f in Rows_log_event::uncompress_buf (this=0x7f779000d390) at /data/src/10.4/sql/log_event.cc:10990 #10 0x0000559995c1395d in Write_rows_compressed_log_event::Write_rows_compressed_log_event (this=0x7f779000d390, buf=0x7f779000d080 "", event_len=254, description_event=0x7f7790006cd0) at /data/src/10.4/sql/log_event.cc:12897 #11 0x0000559995bfc00b in Log_event::read_log_event (buf=0x7f779000d080 "", event_len=254, error=0x7f77e5d80550, fdle=0x7f7790006cd0, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:2177 #12 0x0000559995bfb5fb in Log_event::read_log_event (file=0x7f77e5d806b0, fdle=0x7f7790006cd0, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:1939 #13 0x00005599957efd55 in mysql_show_binlog_events (thd=0x7f7790000b00) at /data/src/10.4/sql/sql_repl.cc:4004 #14 0x00005599957b3505 in mysql_execute_command (thd=0x7f7790000b00) at /data/src/10.4/sql/sql_parse.cc:3887 #15 0x00005599957c08e4 in mysql_parse (thd=0x7f7790000b00, rawbuf=0x7f7790013be8 "SHOW BINLOG EVENTS FROM 1366", length=28, parser_state=0x7f77e5d81650, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8104 #16 0x00005599957adb0e in dispatch_command (command=COM_QUERY, thd=0x7f7790000b00, packet=0x7f779001be11 "", packet_length=28, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1851 #17 0x00005599957ac532 in do_command (thd=0x7f7790000b00) at /data/src/10.4/sql/sql_parse.cc:1396 #18 0x00005599959186de in do_handle_one_connection (connect=0x559999441700) at /data/src/10.4/sql/sql_connect.cc:1402 #19 0x0000559995918462 in handle_one_connection (arg=0x559999441700) at /data/src/10.4/sql/sql_connect.cc:1308 #20 0x00007f77ff036494 in start_thread (arg=0x7f77e5d82700) at pthread_create.c:333 #21 0x00007f77fd63793f in clone () from /lib/x86_64-linux-gnu/libc.so.6 {noformat} {code:sql} SHOW BINLOG EVENTS FROM 3876; {code} {noformat:title=10.4 30641f9df77} mysqld: /data/src/10.4/sql/log_event.cc:12376: Table_map_log_event::Table_map_log_event(const char*, uint, const Format_description_log_event*): Assertion `m_field_metadata_size <= (m_colcnt * 2)' failed. 181220 15:36:33 [ERROR] mysqld got signal 6 ; #7 0x00007f611f6c6ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6 #8 0x0000560a9e1cd75b in Table_map_log_event::Table_map_log_event (this=0x7f60a8013a50, buf=0x7f60a800d080 "", event_len=254, description_event=0x7f60a8006cd0) at /data/src/10.4/sql/log_event.cc:12376 #9 0x0000560a9e1b70c8 in Log_event::read_log_event (buf=0x7f60a800d080 "", event_len=254, error=0x7f611c1f4550, fdle=0x7f60a8006cd0, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:2200 #10 0x0000560a9e1b65fb in Log_event::read_log_event (file=0x7f611c1f46b0, fdle=0x7f60a8006cd0, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:1939 #11 0x0000560a9ddaad55 in mysql_show_binlog_events (thd=0x7f60a8000b00) at /data/src/10.4/sql/sql_repl.cc:4004 #12 0x0000560a9dd6e505 in mysql_execute_command (thd=0x7f60a8000b00) at /data/src/10.4/sql/sql_parse.cc:3887 #13 0x0000560a9dd7b8e4 in mysql_parse (thd=0x7f60a8000b00, rawbuf=0x7f60a8013be8 "SHOW BINLOG EVENTS FROM 3876", length=28, parser_state=0x7f611c1f5650, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8104 #14 0x0000560a9dd68b0e in dispatch_command (command=COM_QUERY, thd=0x7f60a8000b00, packet=0x7f60a801be11 "", packet_length=28, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1851 #15 0x0000560a9dd67532 in do_command (thd=0x7f60a8000b00) at /data/src/10.4/sql/sql_parse.cc:1396 #16 0x0000560a9ded36de in do_handle_one_connection (connect=0x560aa0b1c700) at /data/src/10.4/sql/sql_connect.cc:1402 #17 0x0000560a9ded3462 in handle_one_connection (arg=0x560aa0b1c700) at /data/src/10.4/sql/sql_connect.cc:1308 #18 0x00007f6121182494 in start_thread (arg=0x7f611c1f6700) at pthread_create.c:333 #19 0x00007f611f78393f in clone () from /lib/x86_64-linux-gnu/libc.so.6 {noformat} {code:sql} SHOW BINLOG EVENTS FROM 6191; -- or SHOW BINLOG EVENTS FROM 6367; -- or SHOW BINLOG EVENTS FROM 7951; {code} {noformat:title=10.4 30641f9df77} 181220 15:29:56 [ERROR] mysqld got signal 11 ; #3 <signal handler called> #4 0x0000556cb316374b in inline_mysql_mutex_destroy (that=0xa5a5a5a5a5a5a5a5, src_file=0x556cb35eb5e8 "/data/src/10.4/mysys/my_bitmap.c", src_line=214) at /data/src/10.4/include/mysql/psi/mysql_thread.h:662 #5 0x0000556cb3163f25 in my_bitmap_free (map=0x7fbc1811bb90) at /data/src/10.4/mysys/my_bitmap.c:214 #6 0x0000556cb2b11c76 in Update_rows_log_event::~Update_rows_log_event (this=0x7fbc1811baf0, __in_chrg=<optimized out>) at /data/src/10.4/sql/log_event.cc:14228 #7 0x0000556cb2b11cb6 in Update_rows_log_event::~Update_rows_log_event (this=0x7fbc1811baf0, __in_chrg=<optimized out>) at /data/src/10.4/sql/log_event.cc:14229 #8 0x0000556cb2af7332 in Log_event::read_log_event (buf=0x7fbc180e30f0 "", event_len=27, error=0x7fbc8c2c7550, fdle=0x7fbc1811b970, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:2267 #9 0x0000556cb2af65fb in Log_event::read_log_event (file=0x7fbc8c2c76b0, fdle=0x7fbc1811b970, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:1939 #10 0x0000556cb26ead55 in mysql_show_binlog_events (thd=0x7fbc18000b00) at /data/src/10.4/sql/sql_repl.cc:4004 #11 0x0000556cb26ae505 in mysql_execute_command (thd=0x7fbc18000b00) at /data/src/10.4/sql/sql_parse.cc:3887 #12 0x0000556cb26bb8e4 in mysql_parse (thd=0x7fbc18000b00, rawbuf=0x7fbc18013be8 "SHOW BINLOG EVENTS FROM 7951", length=28, parser_state=0x7fbc8c2c8650, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8104 #13 0x0000556cb26a8b0e in dispatch_command (command=COM_QUERY, thd=0x7fbc18000b00, packet=0x7fbc1801be11 "", packet_length=28, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1851 #14 0x0000556cb26a7532 in do_command (thd=0x7fbc18000b00) at /data/src/10.4/sql/sql_parse.cc:1396 #15 0x0000556cb28136de in do_handle_one_connection (connect=0x556cb67b0700) at /data/src/10.4/sql/sql_connect.cc:1402 #16 0x0000556cb2813462 in handle_one_connection (arg=0x556cb67b0700) at /data/src/10.4/sql/sql_connect.cc:1308 #17 0x00007fbc90a54494 in start_thread (arg=0x7fbc8c2c9700) at pthread_create.c:333 #18 0x00007fbc8f05593f in clone () from /lib/x86_64-linux-gnu/libc.so.6 {noformat} Here is another one that I observed while running similar tests on 10.3 (not from the attached binary log): {noformat:title=10.3 b26736cdb11} mysqld: /data/src/10.3/sql/log_event.cc:12362: Table_map_log_event::Table_map_log_event(const char*, uint, const Format_description_log_event*): Assertion `m_field_metadata_size <= (m_colcnt * 2)' failed. 181220 16:25:17 [ERROR] mysqld got signal 6 ; #7 0x00007f1bfbe03ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6 #8 0x000055a11ac1d82d in Table_map_log_event::Table_map_log_event (this=0x7f1b8c42fb20, buf=0x7f1b8c0467f0 "", event_len=254, description_event=0x7f1b8c438b40) at /data/src/10.3/sql/log_event.cc:12362 #9 0x000055a11ac0738e in Log_event::read_log_event (buf=0x7f1b8c0467f0 "", event_len=254, error=0x7f1bf88e6d10, fdle=0x7f1b8c438b40, crc_check=0 '\000') at /data/src/10.3/sql/log_event.cc:2205 #10 0x000055a11ac068d1 in Log_event::read_log_event (file=0x7f1bf88e6e70, fdle=0x7f1b8c438b40, crc_check=0 '\000') at /data/src/10.3/sql/log_event.cc:1944 #11 0x000055a11a819a90 in mysql_show_binlog_events (thd=0x7f1b8c000b00) at /data/src/10.3/sql/sql_repl.cc:4005 #12 0x000055a11a7dd9b2 in mysql_execute_command (thd=0x7f1b8c000b00) at /data/src/10.3/sql/sql_parse.cc:3880 #13 0x000055a11a7eaec9 in mysql_parse (thd=0x7f1b8c000b00, rawbuf=0x7f1b8c015b68 "SHOW BINLOG EVENTS FROM 6218 /* QNO 2515 CON_ID 14 */", length=53, parser_state=0x7f1bf88e8640, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:8092 #14 0x000055a11a7d807d in dispatch_command (command=COM_QUERY, thd=0x7f1b8c000b00, packet=0x7f1b8c00b1e1 "", packet_length=54, is_com_multi=false, is_next_command=false) at /data/src/10.3/sql/sql_parse.cc:1851 #15 0x000055a11a7d6aa1 in do_command (thd=0x7f1b8c000b00) at /data/src/10.3/sql/sql_parse.cc:1396 #16 0x000055a11a93eab0 in do_handle_one_connection (connect=0x55a11e8e81e0) at /data/src/10.3/sql/sql_connect.cc:1402 #17 0x000055a11a93e834 in handle_one_connection (arg=0x55a11e8e81e0) at /data/src/10.3/sql/sql_connect.cc:1308 #18 0x00007f1bfd8bf494 in start_thread (arg=0x7f1bf88e9700) at pthread_create.c:333 #19 0x00007f1bfbec093f in clone () from /lib/x86_64-linux-gnu/libc.so.6 {noformat} ---- Finally, for the record, this is the basic concurrent test that I ran (not sure if it can reproduce _all_ the above failures, but it can surely reproduce some): {noformat:title=https://github.com/MariaDB/randgen elenst-dev 89b8fe94565} perl ./runall-new.pl --basedir=/home/travis/server/10.4 --duration=350 --threads=2 --mysqld=--log_output=FILE --mysqld=--loose-max-statement-time=5 --mysqld=--lock-wait-timeout=2 --mysqld=--loose-innodb-lock-wait-timeout=1 --mysqld=--loose-debug_assert_on_not_freed_memory=0 --grammar=binevent.yy --gendata=conf/engines/engine_stress.zz --mysqld=--log_bin_trust_function_creators=1 --mysqld=--log-bin --vardir=/home/travis/logs/vardir {noformat} The grammar is attached. It's very big and probably essentially excessive, but I don't expect it to be needed anyway, probably the binlog will be much easier to analyze. |
{{SHOW BINLOG EVENTS FROM <pos>}} causes a variety of failures, some of which are listed below. It is not a race condition issue, but there is some non-determinism in it, I can't figure the cause of it.
The following test case is a bit ugly, but it is a self-contained proof of concept, it shows that the failures happen without any tampering with the binary log: {code:sql} --source include/have_log_bin.inc --source include/have_binlog_format_mixed.inc --source include/have_innodb.inc DROP TABLE /*! IF EXISTS*/ t1; CREATE TABLE `t1` ( `col_int` int, pk integer auto_increment, `col_char_12_key` char(12), `col_int_key` int, `col_char_12` char(12), primary key (pk), key (`col_char_12_key` ), key (`col_int_key` )) ENGINE=InnoDB; INSERT /*! IGNORE */ INTO t1 VALUES (183173120, NULL, 'abcd', 1, 'efghijk'), (1, NULL, 'lmno', 2, 'p'); ALTER TABLE `t1` ENABLE KEYS; --let $max_pos= query_get_value(SHOW MASTER STATUS,Position,1) --let $pos= 1 while ($pos <= $max_pos) { --error 0,1220 eval SHOW BINLOG EVENTS FROM $pos; --inc $pos } {code} {noformat:title=10.1 ASAN 1b471face8} ================================================================= ==15715==ERROR: AddressSanitizer: unknown-crash on address 0x61200019074b at pc 0x55abe4db87f7 bp 0x7ffa25838fc0 sp 0x7ffa25838fb8 READ of size 511 at 0x61200019074b thread T28 #0 0x55abe4db87f6 in my_strndup /data/src/10.2/mysys/my_malloc.c:253 #1 0x55abe4032bbe in Rotate_log_event::Rotate_log_event(char const*, unsigned int, Format_description_log_event const*) /data/src/10.2/sql/log_event.cc:7239 #2 0x55abe40166d8 in Log_event::read_log_event(char const*, unsigned int, char const**, Format_description_log_event const*, char) /data/src/10.2/sql/log_event.cc:2094 #3 0x55abe4015929 in Log_event::read_log_event(st_io_cache*, st_mysql_mutex*, Format_description_log_event const*, char) /data/src/10.2/sql/log_event.cc:1923 #4 0x55abe3800fe2 in mysql_show_binlog_events(THD*) /data/src/10.2/sql/sql_repl.cc:3965 #5 0x55abe377686c in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:3598 #6 0x55abe3792125 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.2/sql/sql_parse.cc:8014 #7 0x55abe376cb0f in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1825 #8 0x55abe3769bb3 in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1379 #9 0x55abe3aaf558 in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1335 #10 0x55abe3aaef6d in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241 #11 0x55abe44c9f9d in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1862 #12 0x7ffa36053493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493) #13 0x7ffa3465493e in __clone (/lib/x86_64-linux-gnu/libc.so.6+0xe893e) 0x6120001907cc is located 0 bytes to the right of 268-byte region [0x6120001906c0,0x6120001907cc) allocated by thread T28 here: #0 0x7ffa362bd73f in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x5473f) #1 0x55abe4de85b9 in sf_malloc /data/src/10.2/mysys/safemalloc.c:118 #2 0x55abe4db7810 in my_malloc /data/src/10.2/mysys/my_malloc.c:101 #3 0x55abe394e199 in String::realloc_raw(unsigned long) /data/src/10.2/sql/sql_string.cc:102 #4 0x55abe35aab08 in String::realloc_with_extra(unsigned long) /data/src/10.2/sql/sql_string.h:376 #5 0x55abe3955048 in String::realloc_with_extra_if_needed(unsigned long) /data/src/10.2/sql/sql_string.h:388 #6 0x55abe3950ace in String::append(char const*, unsigned long) /data/src/10.2/sql/sql_string.cc:499 #7 0x55abe4014bf4 in Log_event::read_log_event(st_io_cache*, String*, Format_description_log_event const*, enum_binlog_checksum_alg) /data/src/10.2/sql/log_event.cc:1795 #8 0x55abe401581e in Log_event::read_log_event(st_io_cache*, st_mysql_mutex*, Format_description_log_event const*, char) /data/src/10.2/sql/log_event.cc:1892 #9 0x55abe3800fe2 in mysql_show_binlog_events(THD*) /data/src/10.2/sql/sql_repl.cc:3965 #10 0x55abe377686c in mysql_execute_command(THD*) /data/src/10.2/sql/sql_parse.cc:3598 #11 0x55abe3792125 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /data/src/10.2/sql/sql_parse.cc:8014 #12 0x55abe376cb0f in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /data/src/10.2/sql/sql_parse.cc:1825 #13 0x55abe3769bb3 in do_command(THD*) /data/src/10.2/sql/sql_parse.cc:1379 #14 0x55abe3aaf558 in do_handle_one_connection(CONNECT*) /data/src/10.2/sql/sql_connect.cc:1335 #15 0x55abe3aaef6d in handle_one_connection /data/src/10.2/sql/sql_connect.cc:1241 #16 0x55abe44c9f9d in pfs_spawn_thread /data/src/10.2/storage/perfschema/pfs.cc:1862 #17 0x7ffa36053493 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x7493) Thread T28 created by T0 here: #0 0x7ffa3628cbba in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x23bba) #1 0x55abe44ca565 in spawn_thread_v1 /data/src/10.2/storage/perfschema/pfs.cc:1912 #2 0x55abe356650e in inline_mysql_thread_create /data/src/10.2/include/mysql/psi/mysql_thread.h:1239 #3 0x55abe357b4ab in create_thread_to_handle_connection(CONNECT*) /data/src/10.2/sql/mysqld.cc:6466 #4 0x55abe357bbb0 in create_new_thread /data/src/10.2/sql/mysqld.cc:6536 #5 0x55abe357cbc7 in handle_connections_sockets() /data/src/10.2/sql/mysqld.cc:6811 #6 0x55abe357aa00 in mysqld_main(int, char**) /data/src/10.2/sql/mysqld.cc:6085 #7 0x55abe35648af in main /data/src/10.2/sql/main.cc:25 #8 0x7ffa3458c2b0 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x202b0) SUMMARY: AddressSanitizer: unknown-crash /data/src/10.2/mysys/my_malloc.c:253 my_strndup Shadow bytes around the buggy address: 0x0c248002a090: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c248002a0a0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c248002a0b0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c248002a0c0: fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa fa 0x0c248002a0d0: fa fa fa fa fa fa fa fa 00 00 00 00 00 00 00 00 =>0x0c248002a0e0: 00 00 00 00 00 00 00 00 00[00]00 00 00 00 00 00 0x0c248002a0f0: 00 00 00 00 00 00 00 00 00 04 fa fa fa fa fa fa 0x0c248002a100: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd 0x0c248002a110: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd 0x0c248002a120: fd fd fd fd fd fd fd fd fd fd fa fa fa fa fa fa 0x0c248002a130: fa fa fa fa fa fa fa fa 00 00 00 00 00 00 00 00 Shadow byte legend (one shadow byte represents 8 application bytes): Addressable: 00 Partially addressable: 01 02 03 04 05 06 07 Heap left redzone: fa Heap right redzone: fb Freed heap region: fd Stack left redzone: f1 Stack mid redzone: f2 Stack right redzone: f3 Stack partial redzone: f4 Stack after return: f5 Stack use after scope: f8 Global redzone: f9 Global init order: f6 Poisoned by user: f7 Contiguous container OOB:fc ASan internal: fe ==15715==ABORTING {noformat} However, since the whole thing is rather unreliable, it might happen that it's not reproducible on a different machine. A wider variety of problems can be observed while running {{SHOW BINLOG EVENTS FROM ...}} with different positions on the attached [^mysql-bin.000001]. The log was produced by MariaDB 10.4, so start 10.4 server with all defaults and {{log-bin=mysql-bin.000001}} with the attached log in the datadir, and run {{SHOW BINLOG EVENTS FROM ...}} with various positions. I've got the following for the first 8000 positions (didn't go further): {code:sql} SHOW BINLOG EVENTS FROM 365; -- or SHOW BINLOG EVENTS FROM 491; -- or SHOW BINLOG EVENTS FROM 2327; -- or SHOW BINLOG EVENTS FROM 4264; {code} {noformat:title=10.4 30641f9df77} mysqld: /data/src/10.4/sql/log_event.cc:10863: Rows_log_event::Rows_log_event(const char*, uint, const Format_description_log_event*): Assertion `var_header_len >= 2' failed. 181220 15:27:02 [ERROR] mysqld got signal 6 ; #7 0x00007fa0d96abee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6 #8 0x000055e744ef82de in Rows_log_event::Rows_log_event (this=0x7fa05800d390, buf=0x7fa05800d080 "", event_len=254, description_event=0x7fa058006d60) at /data/src/10.4/sql/log_event.cc:10863 #9 0x000055e744f00cf8 in Update_rows_log_event::Update_rows_log_event (this=0x7fa05800d390, buf=0x7fa05800d080 "", event_len=254, description_event=0x7fa058006d60) at /data/src/10.4/sql/log_event.cc:14240 #10 0x000055e744ee5fb3 in Log_event::read_log_event (buf=0x7fa05800d080 "", event_len=254, error=0x7fa0d8134550, fdle=0x7fa058006d60, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:2168 #11 0x000055e744ee55fb in Log_event::read_log_event (file=0x7fa0d81346b0, fdle=0x7fa058006d60, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:1939 #12 0x000055e744ad9d55 in mysql_show_binlog_events (thd=0x7fa058000b00) at /data/src/10.4/sql/sql_repl.cc:4004 #13 0x000055e744a9d505 in mysql_execute_command (thd=0x7fa058000b00) at /data/src/10.4/sql/sql_parse.cc:3887 #14 0x000055e744aaa8e4 in mysql_parse (thd=0x7fa058000b00, rawbuf=0x7fa058013be8 "SHOW BINLOG EVENTS FROM 365", length=27, parser_state=0x7fa0d8135650, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8104 #15 0x000055e744a97b0e in dispatch_command (command=COM_QUERY, thd=0x7fa058000b00, packet=0x7fa05801be11 "", packet_length=27, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1851 #16 0x000055e744a96532 in do_command (thd=0x7fa058000b00) at /data/src/10.4/sql/sql_parse.cc:1396 #17 0x000055e744c026de in do_handle_one_connection (connect=0x55e748a968b0) at /data/src/10.4/sql/sql_connect.cc:1402 #18 0x000055e744c02462 in handle_one_connection (arg=0x55e748a968b0) at /data/src/10.4/sql/sql_connect.cc:1308 #19 0x00007fa0db167494 in start_thread (arg=0x7fa0d8136700) at pthread_create.c:333 #20 0x00007fa0d976893f in clone () from /lib/x86_64-linux-gnu/libc.so.6 {noformat} {code:sql} SHOW BINLOG EVENTS FROM 1366; -- or SHOW BINLOG EVENTS FROM 3576; -- or SHOW BINLOG EVENTS FROM 4380; -- or SHOW BINLOG EVENTS FROM 4394; -- or SHOW BINLOG EVENTS FROM 7992; {code} {noformat:title=10.4 30641f9df77} mysqld: /data/src/10.4/sql/log_event.cc:1055: uint32 binlog_get_uncompress_len(const char*): Assertion `(buf[0] & 0xe0) == 0x80' failed. 181220 15:33:56 [ERROR] mysqld got signal 6 ; #7 0x00007f77fd57aee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6 #8 0x0000559995bf8f32 in binlog_get_uncompress_len (buf=0x7f779000d560 "") at /data/src/10.4/sql/log_event.cc:1055 #9 0x0000559995c0ea9f in Rows_log_event::uncompress_buf (this=0x7f779000d390) at /data/src/10.4/sql/log_event.cc:10990 #10 0x0000559995c1395d in Write_rows_compressed_log_event::Write_rows_compressed_log_event (this=0x7f779000d390, buf=0x7f779000d080 "", event_len=254, description_event=0x7f7790006cd0) at /data/src/10.4/sql/log_event.cc:12897 #11 0x0000559995bfc00b in Log_event::read_log_event (buf=0x7f779000d080 "", event_len=254, error=0x7f77e5d80550, fdle=0x7f7790006cd0, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:2177 #12 0x0000559995bfb5fb in Log_event::read_log_event (file=0x7f77e5d806b0, fdle=0x7f7790006cd0, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:1939 #13 0x00005599957efd55 in mysql_show_binlog_events (thd=0x7f7790000b00) at /data/src/10.4/sql/sql_repl.cc:4004 #14 0x00005599957b3505 in mysql_execute_command (thd=0x7f7790000b00) at /data/src/10.4/sql/sql_parse.cc:3887 #15 0x00005599957c08e4 in mysql_parse (thd=0x7f7790000b00, rawbuf=0x7f7790013be8 "SHOW BINLOG EVENTS FROM 1366", length=28, parser_state=0x7f77e5d81650, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8104 #16 0x00005599957adb0e in dispatch_command (command=COM_QUERY, thd=0x7f7790000b00, packet=0x7f779001be11 "", packet_length=28, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1851 #17 0x00005599957ac532 in do_command (thd=0x7f7790000b00) at /data/src/10.4/sql/sql_parse.cc:1396 #18 0x00005599959186de in do_handle_one_connection (connect=0x559999441700) at /data/src/10.4/sql/sql_connect.cc:1402 #19 0x0000559995918462 in handle_one_connection (arg=0x559999441700) at /data/src/10.4/sql/sql_connect.cc:1308 #20 0x00007f77ff036494 in start_thread (arg=0x7f77e5d82700) at pthread_create.c:333 #21 0x00007f77fd63793f in clone () from /lib/x86_64-linux-gnu/libc.so.6 {noformat} {code:sql} SHOW BINLOG EVENTS FROM 3876; {code} {noformat:title=10.4 30641f9df77} mysqld: /data/src/10.4/sql/log_event.cc:12376: Table_map_log_event::Table_map_log_event(const char*, uint, const Format_description_log_event*): Assertion `m_field_metadata_size <= (m_colcnt * 2)' failed. 181220 15:36:33 [ERROR] mysqld got signal 6 ; #7 0x00007f611f6c6ee2 in __assert_fail () from /lib/x86_64-linux-gnu/libc.so.6 #8 0x0000560a9e1cd75b in Table_map_log_event::Table_map_log_event (this=0x7f60a8013a50, buf=0x7f60a800d080 "", event_len=254, description_event=0x7f60a8006cd0) at /data/src/10.4/sql/log_event.cc:12376 #9 0x0000560a9e1b70c8 in Log_event::read_log_event (buf=0x7f60a800d080 "", event_len=254, error=0x7f611c1f4550, fdle=0x7f60a8006cd0, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:2200 #10 0x0000560a9e1b65fb in Log_event::read_log_event (file=0x7f611c1f46b0, fdle=0x7f60a8006cd0, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:1939 #11 0x0000560a9ddaad55 in mysql_show_binlog_events (thd=0x7f60a8000b00) at /data/src/10.4/sql/sql_repl.cc:4004 #12 0x0000560a9dd6e505 in mysql_execute_command (thd=0x7f60a8000b00) at /data/src/10.4/sql/sql_parse.cc:3887 #13 0x0000560a9dd7b8e4 in mysql_parse (thd=0x7f60a8000b00, rawbuf=0x7f60a8013be8 "SHOW BINLOG EVENTS FROM 3876", length=28, parser_state=0x7f611c1f5650, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8104 #14 0x0000560a9dd68b0e in dispatch_command (command=COM_QUERY, thd=0x7f60a8000b00, packet=0x7f60a801be11 "", packet_length=28, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1851 #15 0x0000560a9dd67532 in do_command (thd=0x7f60a8000b00) at /data/src/10.4/sql/sql_parse.cc:1396 #16 0x0000560a9ded36de in do_handle_one_connection (connect=0x560aa0b1c700) at /data/src/10.4/sql/sql_connect.cc:1402 #17 0x0000560a9ded3462 in handle_one_connection (arg=0x560aa0b1c700) at /data/src/10.4/sql/sql_connect.cc:1308 #18 0x00007f6121182494 in start_thread (arg=0x7f611c1f6700) at pthread_create.c:333 #19 0x00007f611f78393f in clone () from /lib/x86_64-linux-gnu/libc.so.6 {noformat} {code:sql} SHOW BINLOG EVENTS FROM 6191; -- or SHOW BINLOG EVENTS FROM 6367; -- or SHOW BINLOG EVENTS FROM 7951; {code} {noformat:title=10.4 30641f9df77} 181220 15:29:56 [ERROR] mysqld got signal 11 ; #3 <signal handler called> #4 0x0000556cb316374b in inline_mysql_mutex_destroy (that=0xa5a5a5a5a5a5a5a5, src_file=0x556cb35eb5e8 "/data/src/10.4/mysys/my_bitmap.c", src_line=214) at /data/src/10.4/include/mysql/psi/mysql_thread.h:662 #5 0x0000556cb3163f25 in my_bitmap_free (map=0x7fbc1811bb90) at /data/src/10.4/mysys/my_bitmap.c:214 #6 0x0000556cb2b11c76 in Update_rows_log_event::~Update_rows_log_event (this=0x7fbc1811baf0, __in_chrg=<optimized out>) at /data/src/10.4/sql/log_event.cc:14228 #7 0x0000556cb2b11cb6 in Update_rows_log_event::~Update_rows_log_event (this=0x7fbc1811baf0, __in_chrg=<optimized out>) at /data/src/10.4/sql/log_event.cc:14229 #8 0x0000556cb2af7332 in Log_event::read_log_event (buf=0x7fbc180e30f0 "", event_len=27, error=0x7fbc8c2c7550, fdle=0x7fbc1811b970, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:2267 #9 0x0000556cb2af65fb in Log_event::read_log_event (file=0x7fbc8c2c76b0, fdle=0x7fbc1811b970, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:1939 #10 0x0000556cb26ead55 in mysql_show_binlog_events (thd=0x7fbc18000b00) at /data/src/10.4/sql/sql_repl.cc:4004 #11 0x0000556cb26ae505 in mysql_execute_command (thd=0x7fbc18000b00) at /data/src/10.4/sql/sql_parse.cc:3887 #12 0x0000556cb26bb8e4 in mysql_parse (thd=0x7fbc18000b00, rawbuf=0x7fbc18013be8 "SHOW BINLOG EVENTS FROM 7951", length=28, parser_state=0x7fbc8c2c8650, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:8104 #13 0x0000556cb26a8b0e in dispatch_command (command=COM_QUERY, thd=0x7fbc18000b00, packet=0x7fbc1801be11 "", packet_length=28, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1851 #14 0x0000556cb26a7532 in do_command (thd=0x7fbc18000b00) at /data/src/10.4/sql/sql_parse.cc:1396 #15 0x0000556cb28136de in do_handle_one_connection (connect=0x556cb67b0700) at /data/src/10.4/sql/sql_connect.cc:1402 #16 0x0000556cb2813462 in handle_one_connection (arg=0x556cb67b0700) at /data/src/10.4/sql/sql_connect.cc:1308 #17 0x00007fbc90a54494 in start_thread (arg=0x7fbc8c2c9700) at pthread_create.c:333 #18 0x00007fbc8f05593f in clone () from /lib/x86_64-linux-gnu/libc.so.6 {noformat} ---- For the record, this is the basic concurrent test that I ran (not sure if it can reproduce _all_ the above failures, but it can surely reproduce some): {noformat:title=https://github.com/MariaDB/randgen elenst-dev 89b8fe94565} perl ./runall-new.pl --basedir=/home/travis/server/10.4 --duration=350 --threads=2 --mysqld=--log_output=FILE --mysqld=--loose-max-statement-time=5 --mysqld=--lock-wait-timeout=2 --mysqld=--loose-innodb-lock-wait-timeout=1 --mysqld=--loose-debug_assert_on_not_freed_memory=0 --grammar=binevent.yy --gendata=conf/engines/engine_stress.zz --mysqld=--log_bin_trust_function_creators=1 --mysqld=--log-bin --vardir=/home/travis/logs/vardir {noformat} The grammar is attached. It's very big and probably essentially excessive, but I don't expect it to be needed anyway, probably the binlog will be much easier to analyze. |
|
10.4 db4a27a |
==9438==ERROR: AddressSanitizer: heap-buffer-overflow on address 0x6170002c5688 at pc 0x000001596a81 bp 0x7f32db0b5f00 sp 0x7f32db0b5ef0
|
READ of size 1 at 0x6170002c5688 thread T43
|
#0 0x1596a80 in net_field_length /home/travis/src/sql-common/pack.c:25
|
#1 0x14dccba in Rows_log_event::Rows_log_event(char const*, unsigned int, Format_description_log_event const*) /home/travis/src/sql/log_event.cc:10956
|
#2 0x14f4afb in Update_rows_log_event::Update_rows_log_event(char const*, unsigned int, Format_description_log_event const*) /home/travis/src/sql/log_event.cc:14543
|
#3 0x14a9c4a in Log_event::read_log_event(char const*, unsigned int, char const**, Format_description_log_event const*, char) /home/travis/src/sql/log_event.cc:2179
|
#4 0x14a8912 in Log_event::read_log_event(st_io_cache*, Format_description_log_event const*, char) /home/travis/src/sql/log_event.cc:1950
|
#5 0xa62cba in mysql_show_binlog_events(THD*) /home/travis/src/sql/sql_repl.cc:4081
|
#6 0x9d1f25 in mysql_execute_command(THD*) /home/travis/src/sql/sql_parse.cc:4010
|
#7 0x9ed5f3 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /home/travis/src/sql/sql_parse.cc:7909
|
#8 0x9c4642 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /home/travis/src/sql/sql_parse.cc:1843
|
#9 0x9c1208 in do_command(THD*) /home/travis/src/sql/sql_parse.cc:1360
|
#10 0xd6ba7f in do_handle_one_connection(CONNECT*) /home/travis/src/sql/sql_connect.cc:1412
|
#11 0xd6b425 in handle_one_connection /home/travis/src/sql/sql_connect.cc:1316
|
#12 0x7f33907716b9 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x76b9)
|
#13 0x7f338f35441c in clone (/lib/x86_64-linux-gnu/libc.so.6+0x10741c)
|
0x6170002c5688 is located 44 bytes to the right of 732-byte region [0x6170002c5380,0x6170002c565c)
|
#0 0x7f33914a5602 in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.2+0x98602)
|
#1 0x2531ace in sf_malloc /home/travis/src/mysys/safemalloc.c:118
|
#2 0x2501588 in my_malloc /home/travis/src/mysys/my_malloc.c:101
|
#3 0x252dcc5 in lf_alloc_new /home/travis/src/mysys/lf_alloc-pin.c:507
|
#4 0x253099f in lf_hash_insert /home/travis/src/mysys/lf_hash.c:403
|
#5 0xd89040 in MDL_map::find_or_insert(LF_PINS*, MDL_key const*) /home/travis/src/sql/mdl.cc:817
|
#6 0xd8d04c in MDL_context::try_acquire_lock_impl(MDL_request*, MDL_ticket**) /home/travis/src/sql/mdl.cc:2092
|
#7 0xd8dca6 in MDL_context::acquire_lock(MDL_request*, double) /home/travis/src/sql/mdl.cc:2247
|
#8 0xd8eddd in MDL_context::acquire_locks(I_P_List<MDL_request, I_P_List_adapter<MDL_request, &MDL_request::next_in_list, &MDL_request::prev_in_list>, I_P_List_counter, I_P_List_no_push_back<MDL_request> >*, double) /home/travis/src/sql/mdl.cc:2447
|
#9 0x859aed in lock_table_names(THD*, DDL_options_st const&, TABLE_LIST*, TABLE_LIST*, unsigned long, unsigned int) /home/travis/src/sql/sql_base.cc:4111
|
#10 0x85a82c in open_tables(THD*, DDL_options_st const&, TABLE_LIST**, unsigned int*, unsigned int, Prelocking_strategy*) /home/travis/src/sql/sql_base.cc:4317
|
#11 0x9b9776 in open_tables /home/travis/src/sql/sql_base.h:258
|
#12 0x9ca727 in lock_tables_open_and_lock_tables /home/travis/src/sql/sql_parse.cc:2888
|
#13 0x9d96a2 in mysql_execute_command(THD*) /home/travis/src/sql/sql_parse.cc:5023
|
#14 0x9ed5f3 in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /home/travis/src/sql/sql_parse.cc:7909
|
#15 0x9c4642 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /home/travis/src/sql/sql_parse.cc:1843
|
#16 0x9c1208 in do_command(THD*) /home/travis/src/sql/sql_parse.cc:1360
|
#17 0xd6ba7f in do_handle_one_connection(CONNECT*) /home/travis/src/sql/sql_connect.cc:1412
|
#18 0xd6b425 in handle_one_connection /home/travis/src/sql/sql_connect.cc:1316
|
#19 0x7f33907716b9 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x76b9)
|
#0 0x7f3391443253 in pthread_create (/usr/lib/x86_64-linux-gnu/libasan.so.2+0x36253)
|
#1 0x256123e in spawn_thread_noop /home/travis/src/mysys/psi_noop.c:187
|
#2 0x6f54a0 in inline_mysql_thread_create /home/travis/src/include/mysql/psi/mysql_thread.h:1268
|
#3 0x70ae7b in create_thread_to_handle_connection(CONNECT*) /home/travis/src/sql/mysqld.cc:6238
|
#4 0x70b59f in create_new_thread(CONNECT*) /home/travis/src/sql/mysqld.cc:6308
|
#5 0x70b947 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /home/travis/src/sql/mysqld.cc:6406
|
#6 0x70c5b3 in handle_connections_sockets() /home/travis/src/sql/mysqld.cc:6564
|
#7 0x70a693 in mysqld_main(int, char**) /home/travis/src/sql/mysqld.cc:5896
|
#8 0x6f3295 in main /home/travis/src/sql/main.cc:25
|
#9 0x7f338f26d82f in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x2082f)
|
SUMMARY: AddressSanitizer: heap-buffer-overflow /home/travis/src/sql-common/pack.c:25 net_field_length
|
0x0c2e80050a80: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
0x0c2e80050a90: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
0x0c2e80050aa0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
0x0c2e80050ab0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
0x0c2e80050ac0: 00 00 00 00 00 00 00 00 00 00 00 04 fa fa fa fa
|
=>0x0c2e80050ad0: fa[fa]fa fa fa fa fa fa fa fa fa fa fa fa fa fa
|
0x0c2e80050ae0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
0x0c2e80050af0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
0x0c2e80050b00: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
0x0c2e80050b10: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
0x0c2e80050b20: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
|
Container overflow: fc
|
|
10.4-18af13b8 |
mysqld: /home/elenst/src/10.4/sql/log_event.cc:1074: uint32 binlog_get_uncompress_len(const char*): Assertion `lenlen >= 1 && lenlen <= 4' failed.
|
190905 11:30:50 [ERROR] mysqld got signal 6 ;
|
|
|
#7 0x00007f2ab32bf0d2 in __assert_fail () from /lib64/libc.so.6
|
#8 0x0000562df3fc4e33 in binlog_get_uncompress_len (buf=0x7f2a101f3d60 "\237<\001\204\024\023\203q9\306\363F\313)\034\232\026\334\356w2Þ±") at /home/elenst/src/10.4/sql/log_event.cc:1074
|
#9 0x0000562df3fdbc97 in Rows_log_event::uncompress_buf (this=0x7f2a10090b80) at /home/elenst/src/10.4/sql/log_event.cc:11042
|
#10 0x0000562df3fe434b in Delete_rows_compressed_log_event::Delete_rows_compressed_log_event (this=0x7f2a10090b80, buf=0x7f2a1021fcc0 "\373\273mj\253Ó‰~:\270*", event_len=10932, description_event=0x7f2a10294480) at /home/elenst/src/10.4/sql/log_event.cc:14330
|
#11 0x0000562df3fc81b4 in Log_event::read_log_event (buf=0x7f2a1021fcc0 "\373\273mj\253Ó‰~:\270*", event_len=10932, error=0x7f2ab00f1d50, fdle=0x7f2a10294480, crc_check=0 '\000') at /home/elenst/src/10.4/sql/log_event.cc:2196
|
#12 0x0000562df3fc76dd in Log_event::read_log_event (file=0x7f2ab00f1eb0, fdle=0x7f2a10294480, crc_check=0 '\000') at /home/elenst/src/10.4/sql/log_event.cc:1950
|
#13 0x0000562df3b4c2d8 in mysql_show_binlog_events (thd=0x7f2a10000b00) at /home/elenst/src/10.4/sql/sql_repl.cc:4081
|
#14 0x0000562df3b0b007 in mysql_execute_command (thd=0x7f2a10000b00) at /home/elenst/src/10.4/sql/sql_parse.cc:4010
|
#15 0x0000562df3b195a1 in mysql_parse (thd=0x7f2a10000b00, rawbuf=0x7f2a10011de8 "SHOW BINLOG EVENTS IN 'mysql-bin.000001' FROM 43973 /* QNO 8054 CON_ID 17 */", length=77, parser_state=0x7f2ab00f3080, is_com_multi=false, is_next_command=false) at /home/elenst/src/10.4/sql/sql_parse.cc:7909
|
#16 0x0000562df3b046ef in dispatch_command (command=COM_QUERY, thd=0x7f2a10000b00, packet=0x7f2a10008321 "", packet_length=78, is_com_multi=false, is_next_command=false) at /home/elenst/src/10.4/sql/sql_parse.cc:1843
|
#17 0x0000562df3b02c77 in do_command (thd=0x7f2a10000b00) at /home/elenst/src/10.4/sql/sql_parse.cc:1360
|
#18 0x0000562df3c8eb21 in do_handle_one_connection (connect=0x562df7cef760) at /home/elenst/src/10.4/sql/sql_connect.cc:1412
|
#19 0x0000562df3c8e850 in handle_one_connection (arg=0x562df7cef760) at /home/elenst/src/10.4/sql/sql_connect.cc:1316
|
#20 0x00007f2ab4fb0dd5 in start_thread () from /lib64/libpthread.so.0
|
#21 0x00007f2ab338dead in clone () from /lib64/libc.so.6
|
Binlog in question attached as mysql-bin.000001.2019-09-05
| Attachment | mysql-bin.000001.2019-09-05 [ 48888 ] |
| Assignee | Andrei Elkin [ elkin ] | Sujatha Sivakumar [ sujatha.sivakumar ] |
|
10.2 879c9ddc |
mysqld: /home/elenst/src/10.2/sql/log_event.cc:4372: Query_log_event::Query_log_event(const char*, uint, const Format_description_log_event*, Log_event_type): Assertion `(pos) + (4) <= (end)' failed.
|
190910 1:28:34 [ERROR] mysqld got signal 6 ;
|
|
|
#7 0x00007f349fe880d2 in __assert_fail () from /lib64/libc.so.6
|
#8 0x000055c4239183e9 in Query_log_event::Query_log_event (this=0x7f342862be00, buf=0x7f34285bb023 "", event_len=108, description_event=0x7f342845f120, event_type=QUERY_EVENT) at /home/elenst/src/10.2/sql/log_event.cc:4372
|
#9 0x000055c423915ac9 in Log_event::read_log_event (buf=0x7f34285bb010 "", event_len=108, error=0x7f349c872e30, fdle=0x7f342845f120, crc_check=0 '\000') at /home/elenst/src/10.2/sql/log_event.cc:2082
|
#10 0x000055c423915520 in Log_event::read_log_event (file=0x7f349c872f90, log_lock=0x0, fdle=0x7f342845f120, crc_check=0 '\000') at /home/elenst/src/10.2/sql/log_event.cc:1924
|
#11 0x000055c4235a8483 in mysql_show_binlog_events (thd=0x7f3428000b00) at /home/elenst/src/10.2/sql/sql_repl.cc:3965
|
#12 0x000055c42356caaf in mysql_execute_command (thd=0x7f3428000b00) at /home/elenst/src/10.2/sql/sql_parse.cc:3645
|
#13 0x000055c423579950 in mysql_parse (thd=0x7f3428000b00, rawbuf=0x7f34280132f8 "SHOW BINLOG EVENTS IN 'mysql-bin.000001' FROM 49139 /* QNO 9886 CON_ID 15 */", length=77, parser_state=0x7f349c874250, is_com_multi=false, is_next_command=false) at /home/elenst/src/10.2/sql/sql_parse.cc:7760
|
#14 0x000055c423567d12 in dispatch_command (command=COM_QUERY, thd=0x7f3428000b00, packet=0x7f34280a3351 "", packet_length=78, is_com_multi=false, is_next_command=false) at /home/elenst/src/10.2/sql/sql_parse.cc:1832
|
#15 0x000055c423566585 in do_command (thd=0x7f3428000b00) at /home/elenst/src/10.2/sql/sql_parse.cc:1386
|
#16 0x000055c4236bdc2f in do_handle_one_connection (connect=0x55c42730a240) at /home/elenst/src/10.2/sql/sql_connect.cc:1336
|
#17 0x000055c4236bd97a in handle_one_connection (arg=0x55c42730a240) at /home/elenst/src/10.2/sql/sql_connect.cc:1241
|
#18 0x00007f34a129fdd5 in start_thread () from /lib64/libpthread.so.0
|
#19 0x00007f349ff56ead in clone () from /lib64/libc.so.6
|
| Status | Open [ 1 ] | In Progress [ 3 ] |
| Attachment | binlogs_2019-08-23.tar.gz [ 48980 ] |
Hello Andrei,
Please review the fixes for MDEV-18046
https://github.com/MariaDB/server/commit/d34839cacbef0f4c76b7aa7ae6165b37b293685c
Thank you.
| Assignee | Sujatha Sivakumar [ sujatha.sivakumar ] | Andrei Elkin [ elkin ] |
| Status | In Progress [ 3 ] | In Review [ 10002 ] |
A way to look at the problem is to catch all excessive allocations (many of which are assert covered). So let's cover all such ones. In the 1st approximation the assert case is to be covered. And then figure out the rest. I remember I was involved in a upstream bug fixes for such project - can point you to a patch, unless you recollect yourself.
| Assignee | Andrei Elkin [ elkin ] | Sujatha Sivakumar [ sujatha.sivakumar ] |
| Status | In Review [ 10002 ] | Stalled [ 10000 ] |
| Status | Stalled [ 10000 ] | In Progress [ 3 ] |
Hello Andrei,
Thank you for the review comments.
Current patch has been split into 9 parts and each part is implemented as a separate commit.
Each part addresses one issue.
When an invalid position is specified in "SHOW BINLOG EVENTS" command and checksums are enabled, an error notification is provided to both client and server error log as shown below.
Example:
MariaDB [test]> SHOW BINLOG EVENTS FROM 40 LIMIT 100;
|
|
|
ERROR 1220 (HY000): Error when executing command SHOW BINLOG EVENTS: Wrong offset or I/O error
|
|
|
2019-11-18 12:13:29 140373369362176 [ERROR] Replication event checksum verification failed while reading from a log file.
|
2019-11-18 12:13:29 140373369362176 [ERROR] Error in Log_event::read_log_event(): 'Replication event checksum verification failed while reading from a log file.', data_len: 103, event_type: 117
|
Build Bot Link: https://github.com/MariaDB/server/commit/dd38280b5be723d3d6a36237e9e918ee6418d7b4
Thank you.
| Assignee | Sujatha Sivakumar [ sujatha.sivakumar ] | Andrei Elkin [ elkin ] |
| Status | In Progress [ 3 ] | In Review [ 10002 ] |
Hello Andrei,
I have addressed your review comments.
Please find the latest changes:
Patch: https://github.com/MariaDB/server/commit/a82003845b7ad65ccdec4f4bdf305171c63610ac
Part1 and Part5 have been modified according to your suggestions.
Build Bot: http://buildbot.askmonty.org/buildbot/grid?category=main&branch=bb-10.1-sujatha
Thank you.
| Assignee | Andrei Elkin [ elkin ] | Sujatha Sivakumar [ sujatha.sivakumar ] |
| Status | In Review [ 10002 ] | Stalled [ 10000 ] |
Hello Andrei,
Please review the 10.2 specific final set of changes.
Implemented a macro to check reading out of buffer.
https://github.com/MariaDB/server/commit/736c686a76c9858aeb977085c78d23d2ea9bb7a2
| Assignee | Sujatha Sivakumar [ sujatha.sivakumar ] | Andrei Elkin [ elkin ] |
| Status | Stalled [ 10000 ] | In Review [ 10002 ] |
| Attachment | EXTRA_ROW_INFO_HDR_BYTES_binary_logs.tar.gz [ 50189 ] |
Another one:
|
10.4 2cff807d |
mysqld: /data/src/10.4/sql/log_event.cc:10941: Rows_log_event::Rows_log_event(const char*, uint, const Format_description_log_event*): Assertion `(end - pos) >= EXTRA_ROW_INFO_HDR_BYTES' failed.
|
200103 16:59:49 [ERROR] mysqld got signal 6 ;
|
|
|
# 2020-01-03T17:00:01 [4364] #7 0x00007fd89f3e9f12 in __GI___assert_fail (assertion=0x56033f2e1c50 "(end - pos) >= EXTRA_ROW_INFO_HDR_BYTES", file=0x56033f2de580 "/data/src/10.4/sql/log_event.cc", line=10941, function=0x56033f2e4c80 <Rows_log_event::Rows_log_event(char const*, unsigned int, Format_description_log_event const*)::__PRETTY_FUNCTION__> "Rows_log_event::Rows_log_event(const char*, uint, const Format_description_log_event*)") at assert.c:101
|
# 2020-01-03T17:00:01 [4364] #8 0x000056033e8c28ad in Rows_log_event::Rows_log_event (this=0x7fd8040bc450, buf=0x7fd8041d49a0 "\201f\344\230\037B", event_len=16923, description_event=0x7fd8042743d0) at /data/src/10.4/sql/log_event.cc:10941
|
# 2020-01-03T17:00:01 [4364] #9 0x000056033e8cbdb2 in Update_rows_log_event::Update_rows_log_event (this=0x7fd8040bc450, buf=0x7fd8041d49a0 "\201f\344\230\037B", event_len=16923, description_event=0x7fd8042743d0) at /data/src/10.4/sql/log_event.cc:14558
|
# 2020-01-03T17:00:01 [4364] #10 0x000056033e8af67d in Log_event::read_log_event (buf=0x7fd8041d49a0 "\201f\344\230\037B", event_len=16923, error=0x7fd8893f8f00, fdle=0x7fd8042743d0, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:2192
|
# 2020-01-03T17:00:01 [4364] #11 0x000056033e8aec06 in Log_event::read_log_event (file=0x7fd8893f9060, fdle=0x7fd8042743d0, crc_check=0 '\000') at /data/src/10.4/sql/log_event.cc:1950
|
# 2020-01-03T17:00:01 [4364] #12 0x000056033e4466c5 in mysql_show_binlog_events (thd=0x7fd804000af0) at /data/src/10.4/sql/sql_repl.cc:4109
|
# 2020-01-03T17:00:01 [4364] #13 0x000056033e405c3d in mysql_execute_command (thd=0x7fd804000af0) at /data/src/10.4/sql/sql_parse.cc:4010
|
# 2020-01-03T17:00:01 [4364] #14 0x000056033e414237 in mysql_parse (thd=0x7fd804000af0, rawbuf=0x7fd804011e68 "SHOW BINLOG EVENTS FROM 26466 LIMIT 23624 /* QNO 6981 CON_ID 17 */", length=66, parser_state=0x7fd8893fa1b0, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:7901
|
# 2020-01-03T17:00:01 [4364] #15 0x000056033e3ff3dc in dispatch_command (command=COM_QUERY, thd=0x7fd804000af0, packet=0x7fd8040083a1 "", packet_length=67, is_com_multi=false, is_next_command=false) at /data/src/10.4/sql/sql_parse.cc:1842
|
# 2020-01-03T17:00:01 [4364] #16 0x000056033e3fda69 in do_command (thd=0x7fd804000af0) at /data/src/10.4/sql/sql_parse.cc:1360
|
# 2020-01-03T17:00:01 [4364] #17 0x000056033e5869df in do_handle_one_connection (connect=0x560343d3cb80) at /data/src/10.4/sql/sql_connect.cc:1412
|
# 2020-01-03T17:00:01 [4364] #18 0x000056033e58672e in handle_one_connection (arg=0x560343d3cb80) at /data/src/10.4/sql/sql_connect.cc:1316
|
# 2020-01-03T17:00:01 [4364] #19 0x00007fd8a13724a4 in start_thread (arg=0x7fd8893fb700) at pthread_create.c:456
|
# 2020-01-03T17:00:01 [4364] #20 0x00007fd89f4a6d0f in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:97
|
Binary logs: EXTRA_ROW_INFO_HDR_BYTES_binary_logs.tar.gz
The last patch 736c686a76c9858aeb977085c78d23d2ea9bb7a2 looks quite good.
Could you please uppercase all the arg:s of the new macro:
--------------------------------------------------------------------------------V
+#define VALIDATE_BYTES_READ(CUR_POS, START, event_len) \
Thanks for a good work!
| Status | In Review [ 10002 ] | Stalled [ 10000 ] |
| Assignee | Andrei Elkin [ elkin ] | Sujatha Sivakumar [ sujatha.sivakumar ] |
Fix for this issue is pushed into 10.1.44. The patch is implemented as 10 different commits in 10.1. 10.2 and higher versions will require one more additional fix because of an issue in binlog uncompress code. 10.1 changes are merged into 10.2 and the binlog uncompress fix is added as "Part 11" of fix. It is pushed into 10.2 branch.
| issue.field.resolutiondate | 2020-01-08 06:21:03.0 | 2020-01-08 06:21:03.802 |
| Fix Version/s | 10.1.44 [ 23912 ] | |
| Fix Version/s | 10.2.31 [ 24017 ] | |
| Fix Version/s | 10.3.22 [ 24018 ] | |
| Fix Version/s | 10.4.12 [ 24019 ] | |
| Fix Version/s | 10.2 [ 14601 ] | |
| Fix Version/s | 10.1 [ 16100 ] | |
| Fix Version/s | 10.3 [ 22126 ] | |
| Fix Version/s | 10.4 [ 22408 ] | |
| Resolution | Fixed [ 1 ] | |
| Status | Stalled [ 10000 ] | Closed [ 6 ] |
| Labels | show_binlog_event |
| Workflow | MariaDB v3 [ 91339 ] | MariaDB v4 [ 155386 ] |
10.3-b96e4424
mysqld: /home/elenst/src/10.3/sql/log_event.cc:10898: Rows_log_event::Rows_log_event(const char*, uint, const Format_description_log_event*): Assertion `(end - pos) >= infoLen' failed.190823 13:36:44 [ERROR] mysqld got signal 6 ;#7 0x00007f359cd430d2 in __assert_fail () from /lib64/libc.so.6#8 0x000055f2c8481cb6 in Rows_log_event::Rows_log_event (this=0x7f34dc2203c0, buf=0x7f34dc0da450 "\201z\346\230\037B", event_len=16923, description_event=0x7f34dc0fa610) at /home/elenst/src/10.3/sql/log_event.cc:10898#9 0x000055f2c848a7d4 in Update_rows_log_event::Update_rows_log_event (this=0x7f34dc2203c0, buf=0x7f34dc0da450 "\201z\346\230\037B", event_len=16923, description_event=0x7f34dc0fa610) at /home/elenst/src/10.3/sql/log_event.cc:14504#10 0x000055f2c846fa93 in Log_event::read_log_event (buf=0x7f34dc0da450 "\201z\346\230\037B", event_len=16923, error=0x7f3574384ba0, fdle=0x7f34dc0fa610, crc_check=0 '\000') at /home/elenst/src/10.3/sql/log_event.cc:2174#11 0x000055f2c846f0fa in Log_event::read_log_event (file=0x7f3574384d00, fdle=0x7f34dc0fa610, crc_check=0 '\000') at /home/elenst/src/10.3/sql/log_event.cc:1945#12 0x000055f2c8072630 in mysql_show_binlog_events (thd=0x7f34dc000b00) at /home/elenst/src/10.3/sql/sql_repl.cc:4005#13 0x000055f2c8036be3 in mysql_execute_command (thd=0x7f34dc000b00) at /home/elenst/src/10.3/sql/sql_parse.cc:3927#14 0x000055f2c80433de in mysql_parse (thd=0x7f34dc000b00, rawbuf=0x7f34dc0114e8 "SHOW BINLOG EVENTS FROM 26172 LIMIT 21717 /* QNO 15070 CON_ID 27 */", length=67, parser_state=0x7f35743864f0, is_com_multi=false, is_next_command=false) at /home/elenst/src/10.3/sql/sql_parse.cc:7829#15 0x000055f2c80310aa in dispatch_command (command=COM_QUERY, thd=0x7f34dc000b00, packet=0x7f34dc008c71 "", packet_length=68, is_com_multi=false, is_next_command=false) at /home/elenst/src/10.3/sql/sql_parse.cc:1856#16 0x000055f2c802fa12 in do_command (thd=0x7f34dc000b00) at /home/elenst/src/10.3/sql/sql_parse.cc:1402#17 0x000055f2c819bf3f in do_handle_one_connection (connect=0x55f2cbbb6d70) at /home/elenst/src/10.3/sql/sql_connect.cc:1403#18 0x000055f2c819bc81 in handle_one_connection (arg=0x55f2cbbb6d70) at /home/elenst/src/10.3/sql/sql_connect.cc:1308#19 0x00007f359ea34dd5 in start_thread () from /lib64/libpthread.so.0#20 0x00007f359ce11ead in clone () from /lib64/libc.so.6All binlogs are attached as binlogs_2019-08-23.tar.gz