[MDEV-23426] rpl.rpl_mdev6020 fails in buildbot, ASAN heap-use-after-free in Version::cmp, rpl_master_has_bug Created: 2020-08-07  Updated: 2023-12-05

Status: Stalled
Project: MariaDB Server
Component/s: Tests
Affects Version/s: 10.2, 10.3, 10.4, 10.5, 10.6, 10.7
Fix Version/s: 10.4, 10.5, 10.6

Type: Bug Priority: Major
Reporter: Alice Sherepa Assignee: Andrei Elkin
Resolution: Unresolved Votes: 0
Labels: None


 Description   

http://buildbot.askmonty.org/buildbot/builders/kvm-asan/builds/4158/steps/mtr_nm/logs/stdio

rpl.rpl_mdev6020 'innodb,mix'            w4 [ fail ]
 
        Test ended at 2020-08-06 10:24:24
 
 
 
CURRENT_TEST: rpl.rpl_mdev6020
 
mysqltest: At line 42: failed in 'select master_pos_wait('master-bin.000002', 343, 300, '')': 2013: Lost connection to MySQL server during query
 
 
 
The result from queries just before the failure was:
 
< snip >
 
connection slave;
 
include/stop_slave.inc
 
connection master;
 
include/rpl_stop_server.inc [server_number=1]
 
include/rpl_start_server.inc [server_number=1]
 
connection slave;
 
SET SQL_LOG_BIN=0;
 
ALTER TABLE mysql.gtid_slave_pos ENGINE = InnoDB;
 
SET SQL_LOG_BIN=1;
 
SET @old_engine= @@GLOBAL.default_storage_engine;
 
SET GLOBAL default_storage_engine=InnoDB;
 
SET @old_parallel= @@GLOBAL.slave_parallel_threads;
 
SET GLOBAL slave_parallel_threads=12;
 
CHANGE MASTER TO master_host='127.0.0.1', master_port=SERVER_MYPORT_1, master_user='root', master_log_file='master-bin.000001', master_log_pos=4;
 
include/start_slave.inc
 
connection master;
 
SET SQL_LOG_BIN=0;
 
ALTER TABLE mysql.gtid_slave_pos ENGINE = InnoDB;
 
SET SQL_LOG_BIN=1;
 
connection slave;
 
 
 
More results from queries before failure can be found in /dev/shm/var/4/log/rpl_mdev6020.log
 
 
 
 
 
Server [mysqld.2 - pid: 23735, winpid: 23735, exit: 256] failed during test run
 
Server log from this test:
 
----------SERVER LOG START-----------
 
2020-08-06 10:24:16 0 [Note] /home/buildbot/buildbot/build/mariadb-10.4.14/sql/mysqld (mysqld 10.4.14-MariaDB-log) starting as process 23736 ...
 
2020-08-06 10:24:16 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 32186)
 
2020-08-06 10:24:16 0 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)
 
2020-08-06 10:24:16 0 [Warning] setrlimit could not change the size of core files to 'infinity';  We may not be able to generate a core file on signals
 
2020-08-06 10:24:16 0 [Note] Plugin 'SEQUENCE' is disabled.
 
2020-08-06 10:24:16 0 [Note] InnoDB: Using Linux native AIO
 
2020-08-06 10:24:16 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
 
2020-08-06 10:24:16 0 [Note] InnoDB: Uses event mutexes
 
2020-08-06 10:24:16 0 [Note] InnoDB: Compressed tables use zlib 1.2.11
 
2020-08-06 10:24:16 0 [Note] InnoDB: Number of pools: 1
 
2020-08-06 10:24:16 0 [Note] InnoDB: Using generic crc32 instructions
 
2020-08-06 10:24:16 0 [Note] mysqld: O_TMPFILE is not supported on /dev/shm/var/tmp/4/mysqld.2 (disabling future attempts)
 
2020-08-06 10:24:16 0 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M
 
2020-08-06 10:24:16 0 [Note] InnoDB: Completed initialization of buffer pool
 
2020-08-06 10:24:16 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
 
2020-08-06 10:24:16 0 [Note] InnoDB: 128 out of 128 rollback segments are active.
 
2020-08-06 10:24:16 0 [Note] InnoDB: Creating shared tablespace for temporary tables
 
2020-08-06 10:24:16 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
 
2020-08-06 10:24:16 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
 
2020-08-06 10:24:16 0 [Note] InnoDB: 10.4.14 started; log sequence number 68328; transaction id 34
 
2020-08-06 10:24:16 0 [Note] InnoDB: Loading buffer pool(s) from /dev/shm/var/4/mysqld.2/data/ib_buffer_pool
 
2020-08-06 10:24:16 0 [Note] InnoDB: Buffer pool(s) load completed at 200806 10:24:16
 
2020-08-06 10:24:16 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'INNODB_CMP' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'FEEDBACK' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'user_variables' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
 
2020-08-06 10:24:16 0 [Note] Plugin 'unix_socket' is disabled.
 
2020-08-06 10:24:16 0 [Warning] /home/buildbot/buildbot/build/mariadb-10.4.14/sql/mysqld: unknown variable 'loose-feedback-debug-startup-interval=20'
 
2020-08-06 10:24:16 0 [Warning] /home/buildbot/buildbot/build/mariadb-10.4.14/sql/mysqld: unknown variable 'loose-feedback-debug-first-interval=60'
 
2020-08-06 10:24:16 0 [Warning] /home/buildbot/buildbot/build/mariadb-10.4.14/sql/mysqld: unknown variable 'loose-feedback-debug-interval=60'
 
2020-08-06 10:24:16 0 [Warning] /home/buildbot/buildbot/build/mariadb-10.4.14/sql/mysqld: unknown option '--loose-pam-debug'
 
2020-08-06 10:24:16 0 [Warning] /home/buildbot/buildbot/build/mariadb-10.4.14/sql/mysqld: unknown option '--loose-aria'
 
2020-08-06 10:24:16 0 [Warning] /home/buildbot/buildbot/build/mariadb-10.4.14/sql/mysqld: unknown variable 'loose-debug-sync-timeout=300'
 
2020-08-06 10:24:17 0 [Note] Server socket created on IP: '127.0.0.1'.
 
2020-08-06 10:24:17 0 [Note] Reading of all Master_info entries succeeded
 
2020-08-06 10:24:17 0 [Note] Added new Master_info '' to hash table
 
2020-08-06 10:24:17 0 [Note] /home/buildbot/buildbot/build/mariadb-10.4.14/sql/mysqld: ready for connections.
 
Version: '10.4.14-MariaDB-log'  socket: '/dev/shm/var/tmp/4/mysqld.2.sock'  port: 16021  MariaDB Server
 
2020-08-06 10:24:17 10 [Note] Deleted Master_info file '/dev/shm/var/4/mysqld.2/data/master.info'.
 
2020-08-06 10:24:17 10 [Note] Deleted Master_info file '/dev/shm/var/4/mysqld.2/data/relay-log.info'.
 
2020-08-06 10:24:17 10 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'
 
2020-08-06 10:24:17 10 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='', master_port='3306', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='16020', master_log_file='master-bin.000001', master_log_pos='4'.
 
2020-08-06 10:24:17 12 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000001' at position 4
 
2020-08-06 10:24:17 13 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 4, relay log './slave-relay-bin.000001' position: 4
 
2020-08-06 10:24:17 12 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication started in log 'master-bin.000001' at position 4
 
2020-08-06 10:24:17 13 [Note] Error reading relay log event: slave SQL thread was killed
 
2020-08-06 10:24:17 13 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000001' at position 329
 
2020-08-06 10:24:17 12 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 329
 
2020-08-06 10:24:22 14 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'
 
2020-08-06 10:24:22 14 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='16020', master_log_file='master-bin.000001', master_log_pos='329'. New state master_host='127.0.0.1', master_port='16020', master_log_file='master-bin.000001', master_log_pos='4'.
 
2020-08-06 10:24:22 16 [Note] Slave I/O thread: Start asynchronous replication to master 'root@127.0.0.1:16020' in log 'master-bin.000001' at position 4
 
2020-08-06 10:24:22 16 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16020',replication started in log 'master-bin.000001' at position 4
 
2020-08-06 10:24:22 17 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 4, relay log './slave-relay-bin.000001' position: 4
 
=================================================================
 
==23736==ERROR: AddressSanitizer: heap-use-after-free on address 0x61200008f378 at pc 0x7f8bc0ee6dfd bp 0x7f8ba9a75100 sp 0x7f8ba9a748a8
 
READ of size 3 at 0x61200008f378 thread T40
 
    #0 0x7f8bc0ee6dfc  (/lib/x86_64-linux-gnu/libasan.so.5+0xdadfc)
 
    #1 0x55840cc5a39a in Version::cmp(Version const&) const /home/buildbot/buildbot/build/mariadb-10.4.14/sql/log_event.h:2746
 
    #2 0x55840cc5a39a in Version::operator<=(Version const&) const /home/buildbot/buildbot/build/mariadb-10.4.14/sql/log_event.h:2767
 
    #3 0x55840cc5a39a in rpl_master_has_bug(Relay_log_info const*, unsigned int, bool, bool (*)(void const*), void const*) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/slave.cc:8088
 
    #4 0x55840d5aef98 in Field_string::compatible_field_size(unsigned int, Relay_log_info*, unsigned short, int*) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/field.cc:7335
 
    #5 0x55840d1fb09a in can_convert_field_to /home/buildbot/buildbot/build/mariadb-10.4.14/sql/rpl_utility.cc:658
 
    #6 0x55840d1fb09a in table_def::compatible_with(THD*, rpl_group_info*, TABLE*, TABLE**) const /home/buildbot/buildbot/build/mariadb-10.4.14/sql/rpl_utility.cc:913
 
    #7 0x55840da012d6 in Rows_log_event::do_apply_event(rpl_group_info*) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/log_event.cc:11486
 
    #8 0x55840cc3f1e7 in Log_event::apply_event(rpl_group_info*) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/log_event.h:1482
 
    #9 0x55840cc3f1e7 in apply_event_and_update_pos_apply /home/buildbot/buildbot/build/mariadb-10.4.14/sql/slave.cc:3960
 
    #10 0x55840cc52625 in apply_event_and_update_pos_for_parallel(Log_event*, THD*, rpl_group_info*) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/slave.cc:4146
 
    #11 0x55840d34105f in rpt_handle_event /home/buildbot/buildbot/build/mariadb-10.4.14/sql/rpl_parallel.cc:61
 
    #12 0x55840d3518cf in handle_rpl_parallel_thread /home/buildbot/buildbot/build/mariadb-10.4.14/sql/rpl_parallel.cc:1360
 
    #13 0x55840e7a4188 in pfs_spawn_thread /home/buildbot/buildbot/build/mariadb-10.4.14/storage/perfschema/pfs.cc:1869
 
    #14 0x7f8bc0d91608 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x9608)
 
    #15 0x7f8bc08d3102 in __clone (/lib/x86_64-linux-gnu/libc.so.6+0x122102)
 
 
 
0x61200008f378 is located 184 bytes inside of 264-byte region [0x61200008f2c0,0x61200008f3c8)
 
freed by thread T35 here:
 
    #0 0x7f8bc0f197cf in __interceptor_free (/lib/x86_64-linux-gnu/libasan.so.5+0x10d7cf)
 
    #1 0x55840d9f56b5 in Log_event::operator delete(void*, unsigned long) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/log_event.h:1360
 
    #2 0x55840d9f56b5 in Format_description_log_event::~Format_description_log_event() /home/buildbot/buildbot/build/mariadb-10.4.14/sql/log_event.h:2820
 
    #3 0x55840d9f56b5 in Format_description_log_event::do_apply_event(rpl_group_info*) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/log_event.cc:6607
 
    #4 0x55840cc3f1e7 in Log_event::apply_event(rpl_group_info*) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/log_event.h:1482
 
    #5 0x55840cc3f1e7 in apply_event_and_update_pos_apply /home/buildbot/buildbot/build/mariadb-10.4.14/sql/slave.cc:3960
 
    #6 0x55840cc52625 in apply_event_and_update_pos_for_parallel(Log_event*, THD*, rpl_group_info*) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/slave.cc:4146
 
    #7 0x55840d34105f in rpt_handle_event /home/buildbot/buildbot/build/mariadb-10.4.14/sql/rpl_parallel.cc:61
 
    #8 0x55840d35d1d0 in rpl_parallel::do_event(rpl_group_info*, Log_event*, unsigned long long) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/rpl_parallel.cc:2921
 
    #9 0x55840cc5686b in exec_relay_log_event /home/buildbot/buildbot/build/mariadb-10.4.14/sql/slave.cc:4355
 
    #10 0x55840cc5686b in handle_slave_sql /home/buildbot/buildbot/build/mariadb-10.4.14/sql/slave.cc:5612
 
    #11 0x55840e7a4188 in pfs_spawn_thread /home/buildbot/buildbot/build/mariadb-10.4.14/storage/perfschema/pfs.cc:1869
 
    #12 0x7f8bc0d91608 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x9608)
 
 
 
previously allocated by thread T35 here:
 
    #0 0x7f8bc0f19bc8 in malloc (/lib/x86_64-linux-gnu/libasan.so.5+0x10dbc8)
 
    #1 0x55840ea00fa6 in my_malloc /home/buildbot/buildbot/build/mariadb-10.4.14/mysys/my_malloc.c:101
 
    #2 0x55840da305f3 in Log_event::operator new(unsigned long) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/log_event.h:1355
 
    #3 0x55840da305f3 in Log_event::read_log_event(char const*, unsigned int, char const**, Format_description_log_event const*, char) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/log_event.cc:2179
 
    #4 0x55840da30c3a in Log_event::read_log_event(st_io_cache*, Format_description_log_event const*, char) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/log_event.cc:1955
 
    #5 0x55840cc3f797 in next_event /home/buildbot/buildbot/build/mariadb-10.4.14/sql/slave.cc:7586
 
    #6 0x55840cc563c9 in exec_relay_log_event /home/buildbot/buildbot/build/mariadb-10.4.14/sql/slave.cc:4267
 
    #7 0x55840cc563c9 in handle_slave_sql /home/buildbot/buildbot/build/mariadb-10.4.14/sql/slave.cc:5612
 
    #8 0x55840e7a4188 in pfs_spawn_thread /home/buildbot/buildbot/build/mariadb-10.4.14/storage/perfschema/pfs.cc:1869
 
    #9 0x7f8bc0d91608 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x9608)
 
 
 
Thread T40 created by T35 here:
 
    #0 0x7f8bc0e46805 in pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
 
    #1 0x55840e7ab8de in spawn_thread_v1 /home/buildbot/buildbot/build/mariadb-10.4.14/storage/perfschema/pfs.cc:1919
 
    #2 0x55840d34562e in inline_mysql_thread_create /home/buildbot/buildbot/build/mariadb-10.4.14/include/mysql/psi/mysql_thread.h:1275
 
    #3 0x55840d34562e in rpl_parallel_change_thread_count /home/buildbot/buildbot/build/mariadb-10.4.14/sql/rpl_parallel.cc:1604
 
    #4 0x55840d349203 in rpl_parallel_activate_pool(rpl_parallel_thread_pool*) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/rpl_parallel.cc:1744
 
    #5 0x55840cc53bbb in handle_slave_sql /home/buildbot/buildbot/build/mariadb-10.4.14/sql/slave.cc:5348
 
    #6 0x55840e7a4188 in pfs_spawn_thread /home/buildbot/buildbot/build/mariadb-10.4.14/storage/perfschema/pfs.cc:1869
 
    #7 0x7f8bc0d91608 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x9608)
 
 
 
Thread T35 created by T32 here:
 
    #0 0x7f8bc0e46805 in pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
 
    #1 0x55840e7ab8de in spawn_thread_v1 /home/buildbot/buildbot/build/mariadb-10.4.14/storage/perfschema/pfs.cc:1919
 
    #2 0x55840cc48785 in inline_mysql_thread_create /home/buildbot/buildbot/build/mariadb-10.4.14/include/mysql/psi/mysql_thread.h:1275
 
    #3 0x55840cc48785 in start_slave_thread(unsigned int, void* (*)(void*), st_mysql_mutex*, st_mysql_mutex*, st_mysql_cond*, unsigned int volatile*, unsigned long volatile*, Master_info*) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/slave.cc:1296
 
    #4 0x55840cc4902c in start_slave_threads(THD*, bool, bool, Master_info*, char const*, char const*, int) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/slave.cc:1422
 
    #5 0x55840cf04718 in start_slave(THD*, Master_info*, bool) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/sql_repl.cc:3236
 
    #6 0x55840ce8f126 in mysql_execute_command(THD*) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/sql_parse.cc:4202
 
    #7 0x55840cea4e3f in mysql_parse(THD*, char*, unsigned int, Parser_state*, bool, bool) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/sql_parse.cc:7896
 
    #8 0x55840cead9e6 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool, bool) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/sql_parse.cc:1834
 
    #9 0x55840ceb37aa in do_command(THD*) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/sql_parse.cc:1352
 
    #10 0x55840d22e5d6 in do_handle_one_connection(CONNECT*) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/sql_connect.cc:1412
 
    #11 0x55840d22eb5e in handle_one_connection /home/buildbot/buildbot/build/mariadb-10.4.14/sql/sql_connect.cc:1316
 
    #12 0x55840e7a4188 in pfs_spawn_thread /home/buildbot/buildbot/build/mariadb-10.4.14/storage/perfschema/pfs.cc:1869
 
    #13 0x7f8bc0d91608 in start_thread (/lib/x86_64-linux-gnu/libpthread.so.0+0x9608)
 
 
 
Thread T32 created by T0 here:
 
    #0 0x7f8bc0e46805 in pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x3a805)
 
    #1 0x55840e7ab8de in spawn_thread_v1 /home/buildbot/buildbot/build/mariadb-10.4.14/storage/perfschema/pfs.cc:1919
 
    #2 0x55840cbf2b0e in inline_mysql_thread_create /home/buildbot/buildbot/build/mariadb-10.4.14/include/mysql/psi/mysql_thread.h:1275
 
    #3 0x55840cbf2b0e in create_thread_to_handle_connection(CONNECT*) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/mysqld.cc:6262
 
    #4 0x55840cbfee32 in create_new_thread(CONNECT*) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/mysqld.cc:6332
 
    #5 0x55840cbff442 in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/mysqld.cc:6430
 
    #6 0x55840cc0065f in handle_connections_sockets() /home/buildbot/buildbot/build/mariadb-10.4.14/sql/mysqld.cc:6588
 
    #7 0x55840cc020f2 in mysqld_main(int, char**) /home/buildbot/buildbot/build/mariadb-10.4.14/sql/mysqld.cc:5920
 
    #8 0x7f8bc07d80b2 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x270b2)
 
 
 
SUMMARY: AddressSanitizer: heap-use-after-free (/lib/x86_64-linux-gnu/libasan.so.5+0xdadfc) 
Shadow bytes around the buggy address:
 
  0x0c2480009e10: fd fd fd fd fd fd fd fd fd fa fa fa fa fa fa fa
 
  0x0c2480009e20: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
 
  0x0c2480009e30: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c2480009e40: fd fd fd fd fd fd fd fd fd fa fa fa fa fa fa fa
 
  0x0c2480009e50: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
 
=>0x0c2480009e60: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd[fd]
 
  0x0c2480009e70: fd fd fd fd fd fd fd fd fd fa fa fa fa fa fa fa
 
  0x0c2480009e80: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
 
  0x0c2480009e90: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c2480009ea0: fd fd fd fd fd fd fd fd fd fd fd fd fd fa fa fa
 
  0x0c2480009eb0: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
 
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
 
  Freed heap region:       fd
 
  Stack left redzone:      f1
 
  Stack mid redzone:       f2
 
  Stack right redzone:     f3
 
  Stack after return:      f5
 
  Stack use after scope:   f8
 
  Global redzone:          f9
 
  Global init order:       f6
 
  Poisoned by user:        f7
 
  Container overflow:      fc
 
  Array cookie:            ac
 
  Intra object redzone:    bb
 
  ASan internal:           fe
 
  Left alloca redzone:     ca
 
  Right alloca redzone:    cb
 
  Shadow gap:              cc
 
==23736==ABORTING
 
----------SERVER LOG END-------------
 
 
 
 
 
 - saving '/dev/shm/var/4/log/rpl.rpl_mdev6020-innodb,mix/' to '/dev/shm/var/log/rpl.rpl_mdev6020-innodb,mix/'
 
worker[4] > Restart  - not started
 
worker[4] > Restart  - not started
 
***Warnings generated in error logs during shutdown after running tests: rpl.rpl_mdev6020
 
 
 
==23736==ERROR: AddressSanitizer: heap-use-after-free on address 0x61200008f378 at pc 0x7f8bc0ee6dfd bp 0x7f8ba9a75100 sp 0x7f8ba9a748a8
 
SUMMARY: AddressSanitizer: heap-use-after-free (/lib/x86_64-linux-gnu/libasan.so.5+0xdadfc)

also on bb-10.3-release
http://buildbot.askmonty.org/buildbot/builders/kvm-asan/builds/4117/steps/mtr_nm/logs/stdio

also I had it in drafts from local rqg runs, failing the same way on 10.2,10.5 (https://jira.mariadb.org/browse/MDEV-16679?focusedCommentId=155775&page=com.atlassian.jira.plugin.system.issuetabpanels%3Acomment-tabpanel#comment-155775)

 Comments   
Comment by Alice Sherepa [ 2020-12-16 ]

http://buildbot.askmonty.org/buildbot/builders/kvm-asan/builds/4958/steps/mtr_nm/logs/stdio

Comment by Marko Mäkelä [ 2021-01-12 ]

10.6 occurrence:

10.6 666565c7f00b0f39bbb459a428efd0093ed05fc8

 
CURRENT_TEST: rpl.rpl_mdev6020
 
mysqltest: At line 42: failed in 'select master_pos_wait('master-bin.000002', 343, 300, '')': 2013: Lost connection to MySQL server during query
 
…
 
==30269==ERROR: AddressSanitizer: use-after-poison on address 0x612000090d10 at pc 0x7f01173a5dfd bp 0x7f01076d5000 sp 0x7f01076d47a8
 
READ of size 3 at 0x612000090d10 thread T23
 
    #0 0x7f01173a5dfc  (/lib/x86_64-linux-gnu/libasan.so.5+0xdadfc)
 
    #1 0x55ed8c4abaca in Version::cmp(Version const&) const /home/buildbot/buildbot/build/mariadb-10.6.0/sql/log_event.h:2756
 
    #2 0x55ed8c4abaca in Version::operator<=(Version const&) const /home/buildbot/buildbot/build/mariadb-10.6.0/sql/log_event.h:2777
 
    #3 0x55ed8c4abaca in rpl_master_has_bug(Relay_log_info const*, unsigned int, bool, bool (*)(void const*), void const*) /home/buildbot/buildbot/build/mariadb-10.6.0/sql/slave.cc:8137
 
    #4 0x55ed8cdbf0a8 in Field_string::compatible_field_size(unsigned int, Relay_log_info const*, unsigned short, int*) const /home/buildbot/buildbot/build/mariadb-10.6.0/sql/field.cc:7512
 
    #5 0x55ed8ca83eb8 in Field::rpl_conv_type_from_same_data_type(unsigned short, Relay_log_info const*, Conv_param const&) const /home/buildbot/buildbot/build/mariadb-10.6.0/sql/rpl_utility_server.cc:421
 
    #6 0x55ed8ca87140 in can_convert_field_to /home/buildbot/buildbot/build/mariadb-10.6.0/sql/rpl_utility_server.cc:855
 
    #7 0x55ed8ca87140 in table_def::compatible_with(THD*, rpl_group_info*, TABLE*, TABLE**) const /home/buildbot/buildbot/build/mariadb-10.6.0/sql/rpl_utility_server.cc:952
 
    #8 0x55ed8d282116 in Rows_log_event::do_apply_event(rpl_group_info*) /home/buildbot/buildbot/build/mariadb-10.6.0/sql/log_event_server.cc:5509

Comment by Alice Sherepa [ 2022-01-18 ]

I am getting in my tests, while testing for preview-10.8-MDEV-11675-rpl-lag-free-alter. 

=================================================================
 
==64697==ERROR: AddressSanitizer: heap-use-after-free on address 0x61400018af80 at pc 0x7f52ea7ff57b bp 0x7f52be3c4190 sp 0x7f52be3c3940
 
READ of size 3 at 0x61400018af80 thread T60
 
    #0 0x7f52ea7ff57a  (/lib/x86_64-linux-gnu/libasan.so.5+0xb857a)
 
    #1 0x562a77fb7639 in Version::cmp(Version const&) const /10.8/sql/log_event.h:2792
 
    #2 0x562a77fb77d0 in Version::operator>(Version const&) const (/10.8/sql/mariadbd+0x19c87d0)
 
    #3 0x562a77fb3399 in rpl_master_has_bug(Relay_log_info const*, unsigned int, bool, bool (*)(void const*), void const*) /10.8/sql/slave.cc:8119
 
    #4 0x562a78a52174 in Field_string::compatible_field_size(unsigned int, Relay_log_info const*, unsigned short, int*) const /10.8/sql/field.cc:7547
 
    #5 0x562a78658b86 in Field::rpl_conv_type_from_same_data_type(unsigned short, Relay_log_info const*, Conv_param const&) const /10.8/sql/rpl_utility_server.cc:421
 
    #6 0x562a78659727 in Field_longstr::rpl_conv_type_from(Conv_source const&, Relay_log_info const*, Conv_param const&) const /10.8/sql/rpl_utility_server.cc:556
 
    #7 0x562a7865ad54 in can_convert_field_to /10.8/sql/rpl_utility_server.cc:855
 
    #8 0x562a7865b65e in table_def::compatible_with(THD*, rpl_group_info*, TABLE*, TABLE**) const /10.8/sql/rpl_utility_server.cc:952
 
    #9 0x562a78e8f233 in Rows_log_event::do_apply_event(rpl_group_info*) /10.8/sql/log_event_server.cc:5882
 
    #10 0x562a77fb739e in Log_event::apply_event(rpl_group_info*) /10.8/sql/log_event.h:1518
 
    #11 0x562a77f98eb5 in apply_event_and_update_pos_apply /10.8/sql/slave.cc:3881
 
    #12 0x562a77f99da8 in apply_event_and_update_pos_for_parallel(Log_event*, THD*, rpl_group_info*) /10.8/sql/slave.cc:4078
 
    #13 0x562a7881e134 in rpt_handle_event /10.8/sql/rpl_parallel.cc:62
 
    #14 0x562a7882624b in handle_rpl_parallel_thread /10.8/sql/rpl_parallel.cc:1409
 
    #15 0x562a79312a8b in pfs_spawn_thread /10.8/storage/perfschema/pfs.cc:2201
 
    #16 0x7f52ea153fa2 in start_thread /build/glibc-vjB4T1/glibc-2.28/nptl/pthread_create.c:486
 
    #17 0x7f52e9d5e4ce in clone (/lib/x86_64-linux-gnu/libc.so.6+0xf94ce)
 
 
 
0x61400018af80 is located 320 bytes inside of 404-byte region [0x61400018ae40,0x61400018afd4)
 
freed by thread T54 here:
 
    #0 0x7f52ea82ffb0 in __interceptor_free (/lib/x86_64-linux-gnu/libasan.so.5+0xe8fb0)
 
    #1 0x562a79f35def in free_memory /10.8/mysys/safemalloc.c:297
 
    #2 0x562a79f3529e in sf_free /10.8/mysys/safemalloc.c:203
 
    #3 0x562a79f04431 in my_free /10.8/mysys/my_malloc.c:211
 
    #4 0x562a77fb6e95 in Log_event::operator delete(void*, unsigned long) /10.8/sql/log_event.h:1396
 
    #5 0x562a77fb78b2 in Format_description_log_event::~Format_description_log_event() /10.8/sql/log_event.h:2866
 
    #6 0x562a78e72879 in Format_description_log_event::do_apply_event(rpl_group_info*) /10.8/sql/log_event_server.cc:2720
 
    #7 0x562a77fb739e in Log_event::apply_event(rpl_group_info*) /10.8/sql/log_event.h:1518
 
    #8 0x562a77f98eb5 in apply_event_and_update_pos_apply /10.8/sql/slave.cc:3881
 
    #9 0x562a77f99da8 in apply_event_and_update_pos_for_parallel(Log_event*, THD*, rpl_group_info*) /10.8/sql/slave.cc:4078
 
    #10 0x562a7881e134 in rpt_handle_event /10.8/sql/rpl_parallel.cc:62
 
    #11 0x562a788326d5 in rpl_parallel::do_event(rpl_group_info*, Log_event*, unsigned long long) /10.8/sql/rpl_parallel.cc:3246
 
    #12 0x562a77f9aee6 in exec_relay_log_event /10.8/sql/slave.cc:4331
 
    #13 0x562a77fa3253 in handle_slave_sql /10.8/sql/slave.cc:5594
 
    #14 0x562a79312a8b in pfs_spawn_thread /10.8/storage/perfschema/pfs.cc:2201
 
    #15 0x7f52ea153fa2 in start_thread /build/glibc-vjB4T1/glibc-2.28/nptl/pthread_create.c:486
 
 
 
previously allocated by thread T54 here:
 
    #0 0x7f52ea830330 in __interceptor_malloc (/lib/x86_64-linux-gnu/libasan.so.5+0xe9330)
 
    #1 0x562a79f34c84 in sf_malloc /10.8/mysys/safemalloc.c:126
 
    #2 0x562a79f03683 in my_malloc /10.8/mysys/my_malloc.c:90
 
    #3 0x562a77fb6e77 in Log_event::operator new(unsigned long) /10.8/sql/log_event.h:1391
 
    #4 0x562a78e3a755 in Log_event::read_log_event(unsigned char const*, unsigned int, char const**, Format_description_log_event const*, char) /10.8/sql/log_event.cc:1180
 
    #5 0x562a78e39399 in Log_event::read_log_event(st_io_cache*, Format_description_log_event const*, char) /10.8/sql/log_event.cc:954
 
    #6 0x562a77fb0f86 in next_event /10.8/sql/slave.cc:7616
 
    #7 0x562a77f9a3db in exec_relay_log_event /10.8/sql/slave.cc:4241
 
    #8 0x562a77fa3253 in handle_slave_sql /10.8/sql/slave.cc:5594
 
    #9 0x562a79312a8b in pfs_spawn_thread /10.8/storage/perfschema/pfs.cc:2201
 
    #10 0x7f52ea153fa2 in start_thread /build/glibc-vjB4T1/glibc-2.28/nptl/pthread_create.c:486
 
 
 
Thread T60 created by T54 here:
 
    #0 0x7f52ea797db0 in __interceptor_pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x50db0)
 
    #1 0x562a7930d98a in my_thread_create /10.8/storage/perfschema/my_thread.h:48
 
    #2 0x562a79312e7a in pfs_spawn_thread_v1 /10.8/storage/perfschema/pfs.cc:2252
 
    #3 0x562a7881cb65 in inline_mysql_thread_create /10.8/include/mysql/psi/mysql_thread.h:1139
 
    #4 0x562a78827c19 in rpl_parallel_change_thread_count /10.8/sql/rpl_parallel.cc:1653
 
    #5 0x562a78828e86 in rpl_parallel_activate_pool(rpl_parallel_thread_pool*) /10.8/sql/rpl_parallel.cc:1797
 
    #6 0x562a77fa16dd in handle_slave_sql /10.8/sql/slave.cc:5329
 
    #7 0x562a79312a8b in pfs_spawn_thread /10.8/storage/perfschema/pfs.cc:2201
 
    #8 0x7f52ea153fa2 in start_thread /build/glibc-vjB4T1/glibc-2.28/nptl/pthread_create.c:486
 
 
 
Thread T54 created by T52 here:
 
    #0 0x7f52ea797db0 in __interceptor_pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x50db0)
 
    #1 0x562a7930d98a in my_thread_create /10.8/storage/perfschema/my_thread.h:48
 
    #2 0x562a79312e7a in pfs_spawn_thread_v1 /10.8/storage/perfschema/pfs.cc:2252
 
    #3 0x562a77f8019e in inline_mysql_thread_create /10.8/include/mysql/psi/mysql_thread.h:1139
 
    #4 0x562a77f88019 in start_slave_thread(unsigned int, void* (*)(void*), st_mysql_mutex*, st_mysql_mutex*, st_mysql_cond*, unsigned int volatile*, unsigned long volatile*, Master_info*) /10.8/sql/slave.cc:1150
 
    #5 0x562a77f88b1b in start_slave_threads(THD*, bool, bool, Master_info*, char const*, char const*, int) /10.8/sql/slave.cc:1276
 
    #6 0x562a782fe4aa in start_slave(THD*, Master_info*, bool) /10.8/sql/sql_repl.cc:3274
 
    #7 0x562a78229ec2 in mysql_execute_command(THD*, bool) /10.8/sql/sql_parse.cc:4245
 
    #8 0x562a78244949 in mysql_parse(THD*, char*, unsigned int, Parser_state*) /10.8/sql/sql_parse.cc:8028
 
    #9 0x562a7821b0a0 in dispatch_command(enum_server_command, THD*, char*, unsigned int, bool) /10.8/sql/sql_parse.cc:1894
 
    #10 0x562a78217d95 in do_command(THD*, bool) /10.8/sql/sql_parse.cc:1402
 
    #11 0x562a786a5ac7 in do_handle_one_connection(CONNECT*, bool) /10.8/sql/sql_connect.cc:1418
 
    #12 0x562a786a534c in handle_one_connection /10.8/sql/sql_connect.cc:1312
 
    #13 0x562a79312a8b in pfs_spawn_thread /10.8/storage/perfschema/pfs.cc:2201
 
    #14 0x7f52ea153fa2 in start_thread /build/glibc-vjB4T1/glibc-2.28/nptl/pthread_create.c:486
 
 
 
Thread T52 created by T0 here:
 
    #0 0x7f52ea797db0 in __interceptor_pthread_create (/lib/x86_64-linux-gnu/libasan.so.5+0x50db0)
 
    #1 0x562a7930d98a in my_thread_create /10.8/storage/perfschema/my_thread.h:48
 
    #2 0x562a79312e7a in pfs_spawn_thread_v1 /10.8/storage/perfschema/pfs.cc:2252
 
    #3 0x562a77e77536 in inline_mysql_thread_create /10.8/include/mysql/psi/mysql_thread.h:1139
 
    #4 0x562a77e8e95f in create_thread_to_handle_connection(CONNECT*) /10.8/sql/mysqld.cc:5969
 
    #5 0x562a77e8efca in create_new_thread(CONNECT*) /10.8/sql/mysqld.cc:6028
 
    #6 0x562a77e8f33c in handle_accepted_socket(st_mysql_socket, st_mysql_socket) /10.8/sql/mysqld.cc:6090
 
    #7 0x562a77e8fd3b in handle_connections_sockets() /10.8/sql/mysqld.cc:6214
 
    #8 0x562a77e8e1c6 in mysqld_main(int, char**) /10.8/sql/mysqld.cc:5864
 
    #9 0x562a77e76784 in main /10.8/sql/main.cc:34
 
    #10 0x7f52e9c8909a in __libc_start_main ../csu/libc-start.c:308
 
 
 
SUMMARY: AddressSanitizer: heap-use-after-free (/lib/x86_64-linux-gnu/libasan.so.5+0xb857a) 
Shadow bytes around the buggy address:
 
  0x0c28800295a0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c28800295b0: fd fd fd fd fd fd fd fd fd fd fd fa fa fa fa fa
 
  0x0c28800295c0: fa fa fa fa fa fa fa fa fd fd fd fd fd fd fd fd
 
  0x0c28800295d0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
  0x0c28800295e0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
 
=>0x0c28800295f0:[fd]fd fd fd fd fd fd fd fd fd fd fa fa fa fa fa
 
  0x0c2880029600: fa fa fa fa fa fa fa fa 00 00 00 00 00 00 00 00
 
  0x0c2880029610: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c2880029620: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
 
  0x0c2880029630: 00 00 00 00 00 00 00 00 00 04 fa fa fa fa fa fa
 
  0x0c2880029640: 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
 
  Freed heap region:       fd
 
  Stack left redzone:      f1
 
  Stack mid redzone:       f2
 
  Stack right redzone:     f3
 
  Stack after return:      f5
 
  Stack use after scope:   f8
 
  Global redzone:          f9
 
  Global init order:       f6
 
  Poisoned by user:        f7
 
  Container overflow:      fc
 
  Array cookie:            ac
 
  Intra object redzone:    bb
 
  ASan internal:           fe
 
  Left alloca redzone:     ca
 
  Right alloca redzone:    cb
 
==64697==ABORTING

Comment by Julien Fritsch [ 2023-12-05 ]

Automated message:
----------------------------
Since this issue has not been updated since 6 weeks, it's time to move it back to Stalled.

Comment by JiraAutomate [ 2023-12-05 ]

Automated message:
----------------------------
Since this issue has not been updated since 6 weeks, it's time to move it back to Stalled.

Generated at Thu Feb 08 09:22:18 UTC 2024 using Jira 8.20.16#820016-sha1:9d11dbea5f4be3d4cc21f03a88dd11d8c8687422.