[#MDEV-21569] rpl.rpl_row_corruption failed in buildbot: sql_set_variables: mutex: LOCK_global_system

10.2 ef1e488be369b3d3c7eb26cfba1f4484

rpl.rpl_row_corruption 'row'             w1 [ fail ]

        Test ended at 2020-01-02 01:41:39

CURRENT_TEST: rpl.rpl_row_corruption

mysqltest: At line 113: query 'SET GLOBAL debug_dbug= @save_debug' failed: 2013: Lost connection to MySQL server during query

The result from queries just before the failure was:

< snip >

BINLOG '

SOgWTg8BAAAAbgAAAHIAAAAAAAQANS42LjMtbTUtZGVidWctbG9nAAAAAAAAAAAAAAAAAAAAAAAA

AAAAAAAAAAAAAAAAAABI6BZOEzgNAAgAEgAEBAQEEgAAVgAEGggAAAAICAgCAAAAAAVAYI8=

'/*!*/;

SET GLOBAL debug_dbug="+d,inject_tblmap_same_id_maps_diff_table";

BINLOG '

SOgWThMBAAAAKQAAAAYDAAAAAEIAAAAAAAEABHRlc3QAAnQxAAEDAAE=

SOgWThMBAAAAKQAAAC8DAAAAAEMAAAAAAAEABHRlc3QAAnQyAAEDAAE=

SOgWThgBAAAAKAAAAFcDAAAAAEIAAAAAAAAAAf///gEAAAD+AwAAAA==

SOgWThgBAAAAKAAAAH8DAAAAAEMAAAAAAAEAAf///gEAAAD+BAAAAA==

'/*!*/;

ERROR HY000: Fatal error: Found table map event mapping table id 0 which was already mapped but with different settings.

DROP TABLE t1,t2;

connection slave;

SET GLOBAL debug_dbug="-d,inject_tblmap_same_id_maps_diff_table";

connection master;

DROP TABLE t1_11753004;

DROP TABLE t2_11753004_ign;

connection slave;

SET GLOBAL debug_dbug= @save_debug;

More results from queries before failure can be found in /dev/shm/var/1/log/rpl_row_corruption.log

Server [mysqld.2 - pid: 28758, winpid: 28758, exit: 256] failed during test run

Server log from this test:

----------SERVER LOG START-----------

2020-01-02  1:41:34 139914576587008 [Note] /home/buildbot/buildbot/build/mariadb-10.2.31/sql/mysqld (mysqld 10.2.31-MariaDB-debug-log) starting as process 28761 ...

2020-01-02  1:41:34 139914576587008 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4186)

2020-01-02  1:41:34 139914576587008 [Warning] Changed limits: max_open_files: 1024  max_connections: 151 (was 151)  table_cache: 421 (was 2000)

2020-01-02  1:41:34 139914576587008 [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-01-02  1:41:34 139914576587008 [Note] Plugin 'SEQUENCE' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'partition' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!

2020-01-02  1:41:34 139914576587008 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins

2020-01-02  1:41:34 139914576587008 [Note] InnoDB: Uses event mutexes

2020-01-02  1:41:34 139914576587008 [Note] InnoDB: Compressed tables use zlib 1.2.8

2020-01-02  1:41:34 139914576587008 [Note] InnoDB: Using Linux native AIO

2020-01-02  1:41:34 139914576587008 [Note] InnoDB: Number of pools: 1

2020-01-02  1:41:34 139914576587008 [Note] InnoDB: Using generic crc32 instructions

2020-01-02  1:41:34 139914576587008 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M

2020-01-02  1:41:34 139914576587008 [Note] InnoDB: Completed initialization of buffer pool

2020-01-02  1:41:34 139914293466880 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().

2020-01-02  1:41:34 139914576587008 [Note] InnoDB: Highest supported file format is Barracuda.

2020-01-02  1:41:34 139914576587008 [Note] InnoDB: 128 out of 128 rollback segments are active.

2020-01-02  1:41:34 139914576587008 [Note] InnoDB: Creating shared tablespace for temporary tables

2020-01-02  1:41:34 139914576587008 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...

2020-01-02  1:41:34 139914576587008 [Note] InnoDB: File './ibtmp1' size is now 12 MB.

2020-01-02  1:41:34 139914576587008 [Note] InnoDB: Waiting for purge to start

2020-01-02  1:41:34 139914576587008 [Note] InnoDB: 5.7.28 started; log sequence number 1628840

2020-01-02  1:41:34 139914196408064 [Note] InnoDB: Loading buffer pool(s) from /dev/shm/var/1/mysqld.2/data/ib_buffer_pool

2020-01-02  1:41:34 139914196408064 [Note] InnoDB: Buffer pool(s) load completed at 200102  1:41:34

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_LOCKS' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_MUTEXES' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_CMPMEM' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_CMP_PER_INDEX' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_CMP' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_FT_DELETED' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_CMP_RESET' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_BUFFER_PAGE_LRU' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'FEEDBACK' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'user_variables' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_SYS_FOREIGN_COLS' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_BUFFER_POOL_STATS' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_TRX' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_SYS_FOREIGN' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_SYS_TABLES' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_BUFFER_PAGE' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_METRICS' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_SYS_VIRTUAL' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.

2020-01-02  1:41:34 139914576587008 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.

2020-01-02  1:41:34 139914576587008 [Warning] /home/buildbot/buildbot/build/mariadb-10.2.31/sql/mysqld: unknown option '--loose-pam-debug'

2020-01-02  1:41:34 139914576587008 [Note] Server socket created on IP: '127.0.0.1'.

2020-01-02  1:41:34 139914576587008 [Note] Reading of all Master_info entries succeeded

2020-01-02  1:41:34 139914576587008 [Note] Added new Master_info '' to hash table

2020-01-02  1:41:34 139914576587008 [Note] /home/buildbot/buildbot/build/mariadb-10.2.31/sql/mysqld: ready for connections.

Version: '10.2.31-MariaDB-debug-log'  socket: '/dev/shm/var/tmp/1/mysqld.2.sock'  port: 16041  Source distribution

2020-01-02  1:41:35 139914140481280 [Note] Deleted Master_info file '/dev/shm/var/1/mysqld.2/data/master.info'.

2020-01-02  1:41:35 139914140481280 [Note] Deleted Master_info file '/dev/shm/var/1/mysqld.2/data/relay-log.info'.

2020-01-02  1:41:35 139914140481280 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'

2020-01-02  1:41:35 139914140481280 [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='16040', master_log_file='master-bin.000001', master_log_pos='4'.

2020-01-02  1:41:35 139914135820032 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 4, relay log './slave-relay-bin.000001' position: 4

2020-01-02  1:41:35 139914136352512 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication started in log 'master-bin.000001' at position 4

2020-01-02  1:41:36 139914135820032 [Note] Error reading relay log event: slave SQL thread was killed

2020-01-02  1:41:36 139914135820032 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000001' at position 1141

2020-01-02  1:41:36 139914136352512 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 1141

2020-01-02  1:41:36 139914135820032 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 1141, relay log './slave-relay-bin.000002' position: 1441

2020-01-02  1:41:36 139914136352512 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication started in log 'master-bin.000001' at position 1141

2020-01-02  1:41:36 139914135820032 [ERROR] Slave SQL: Fatal error: Found table map event mapping table id 0 which was already mapped but with different settings. Gtid 0-1-5, Internal MariaDB error code: 1593

2020-01-02  1:41:36 139914135820032 [ERROR] Error running query, slave SQL thread aborted. Fix the problem, and restart the slave SQL thread with "SLAVE START". We stopped at log 'master-bin.000001' position 1141

2020-01-02  1:41:36 139914135820032 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000001' at position 1141

2020-01-02  1:41:36 139914136352512 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)

2020-01-02  1:41:36 139914136352512 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 1597

sql_set_variables: mutex: LOCK_global_system_variables (0x34d0280) unlocking

mysql_execute_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/sql_parse.cc:5982

close_thread_tables: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/sql_base.cc:725

debug_sync: debug_sync_point: hit: 'before_close_thread_tables'

mysql_parse: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/sql_parse.cc:7757

lex_end: enter: lex: 0x62a0000b7d40

Query_arena::free_items: info: free item: 0x62b00003f388

dispatch_command: info: query ready

dispatch_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/sql_parse.cc:2383

net_send_ok: info: affected_rows: 0  id: 0  status: 2  warning_count: 0

net_send_ok: packet_header: Memory: 0x7f404c540b60  Bytes: (4)

07 00 00 01

vio_is_blocking: exit: 0

vio_write: enter: sd: 71  buf: 0x629000172208  size: 11

vio_write: exit: 11

net_send_ok: info: OK sent, so no more error sending allowed

killed_errno: enter: killed: 0  killed_errno: 0

dispatch_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/sql_parse.cc:2407

dispatch_command: mutex: LOCK_thd_data (0x62a0000b5b50) locking

dispatch_command: mutex: LOCK_thd_data (0x62a0000b5b50) locked

dispatch_command: mutex: LOCK_thd_data (0x62a0000b5b50) unlocking

free_root: enter: root: 0x62a0000b9378  flags: 1

debug_sync: debug_sync_point: hit: 'dispatch_command_end'

my_net_set_read_timeout: enter: timeout: 28800

debug_sync: debug_sync_point: hit: 'before_do_command_net_read'

vio_is_blocking: exit: 0

vio_read: enter: sd: 71  buf: 0x629000172208  size: 4

vio_io_wait: enter: timeout: 28800000

vio_read: read_data: Memory: 0x629000172208  Bytes: (4)

0C 00 00 00

vio_read: exit: 4

do_command: packet_header: Memory: 0x629000172208  Bytes: (4)

0C 00 00 00

do_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/mysqld.cc:1231

vio_read: enter: sd: 71  buf: 0x629000172208  size: 12

vio_read: read_data: Memory: 0x629000172208  Bytes: (12)

03 53 54 41 52 54 20 53 4C 41 56 45

vio_read: exit: 12

fetch_command: info: Command on TCP/IP = 3 (Query)

my_net_set_read_timeout: enter: timeout: 30

dispatch_command: info: command: 3 Query

debug_sync: debug_sync_point: hit: 'dispatch_command_before_set_time'

alloc_root: enter: root: 0x62a0000b9378

alloc_root: exit: ptr: 0x62b00003f228

dispatch_command: mutex: LOCK_thd_data (0x62a0000b5b50) locking

dispatch_command: mutex: LOCK_thd_data (0x62a0000b5b50) locked

dispatch_command: mutex: LOCK_thd_data (0x62a0000b5b50) unlocking

dispatch_command: mutex: LOCK_log (0x61e00000f088) locking

dispatch_command: mutex: LOCK_log (0x61e00000f088) locked

my_b_flush_io_cache: enter: cache: 0x61e00000f418

my_write: my: fd: 18  Buffer: 0x625000032108  Count: 26  MyFlags: 532

dispatch_command: mutex: LOCK_log (0x61e00000f088) unlocking

dispatch_command: query: START SLAVE

alloc_root: enter: root: 0x62a0000b9378

alloc_root: exit: ptr: 0x62b00003f2a0

lex_start: info: Lex 0x62a0000b7d40

alloc_root: enter: root: 0x62a0000b9378

alloc_root: exit: ptr: 0x62b00003f2b8

THD::reset_for_next_command: info: Lex and stmt_lex: 0x62a0000b7d40

reset_current_stmt_binlog_format_row: debug: temporary_tables: no, in_sub_stmt: no, system_thread: NON_SYSTEM_THREAD

THD::reset_for_next_command: debug: is_current_stmt_binlog_format_row(): 1

debug_sync: debug_sync_point: hit: 'before_execute_sql_command'

rpl_load_gtid_slave_state: mutex: LOCK_slave_state (0x61300000d9a8) locking

rpl_load_gtid_slave_state: mutex: LOCK_slave_state (0x61300000d9a8) locked

rpl_load_gtid_slave_state: mutex: LOCK_slave_state (0x61300000d9a8) unlocking

get_master_info: mutex: LOCK_active_mi (0x34d0b40) locking

get_master_info: mutex: LOCK_active_mi (0x34d0b40) locked

get_master_info: enter: connection_name: ''

my_hash_first_from_hash_value: exit: found key at 0

get_master_info: mutex: sleep_lock (0x62a000091c70) locking

my_hash_first_from_hash_value: exit: found key at 54

get_master_info: mutex: sleep_lock (0x62a000091c70) locked

get_master_info: info: users: 1

get_master_info: mutex: sleep_lock (0x62a000091c70) unlocking

get_master_info: mutex: LOCK_active_mi (0x34d0b40) unlocking

check_access: enter: db: *any*  want_access: 32768  master_access: 536870911

check_access: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/sql_parse.cc:6435

lock_slave_threads: mutex: start_stop_lock (0x62a000091d20) locking

lock_slave_threads: mutex: start_stop_lock (0x62a000091d20) locked

init_master_info: mutex: LOCK_log (0x62a0000923a8) locking

my_hash_first_from_hash_value: exit: found key at 6

init_master_info: mutex: LOCK_log (0x62a0000923a8) locked

my_b_seek: enter: pos: 0

my_b_flush_io_cache: enter: cache: 0x62a000092738

my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000092788) locking

my_hash_first_from_hash_value: exit: found key at 9

my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000092788) locked

my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000092788) unlocking

init_master_info: mutex: LOCK_log (0x62a0000923a8) unlocking

start_slave: mutex: data_lock (0x62a000093e60) locking

my_hash_first_from_hash_value: exit: found key at 3

start_slave: mutex: data_lock (0x62a000093e60) locked

start_slave: mutex: data_lock (0x62a000093e60) unlocking

start_slave_thread: mutex: run_lock (0x62a000091bc0) locking

start_slave_thread: mutex: run_lock (0x62a000091bc0) locked

start_slave_thread: info: Creating new slave thread

my_malloc: my: size: 488  my_flags: 16

my_malloc: info: global thd memory_used: 169880  size: 496

my_malloc: exit: ptr: 0x61500003f288

start_slave_thread: sleep: Waiting for slave thread to start

start_slave_thread: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/slave.cc:960

handle_slave_io: mutex: LOCK_thread_id (0x34d0c20) locking

handle_slave_io: mutex: LOCK_thread_id (0x34d0c20) locked

handle_slave_io: mutex: LOCK_thread_id (0x34d0c20) unlocking

my_malloc: my: size: 22416  my_flags: 4120

my_malloc: info: global memory_used: 16170840  size: 22424

my_malloc: exit: ptr: 0x62a0000ba208

safe_mutex_init: enter: mutex: 0x62a0000ba328  name: &m_LOCK_wait_status

my_hash_init: enter: hash:0x62a0000bbcb0  size: 16

my_malloc: my: size: 256  my_flags: 0

my_malloc: info: global memory_used: 16193264  size: 264

my_malloc: exit: ptr: 0x612000082cc8

my_hash_init: enter: hash:0x62a0000bbd18  size: 16

my_malloc: my: size: 256  my_flags: 0

my_malloc: info: global memory_used: 16193528  size: 264

my_malloc: exit: ptr: 0x612000082b48

init_alloc_root: enter: root: 0x62a0000bd628  prealloc: 0

init_alloc_root: enter: root: 0x62a0000bdc70  prealloc: 0

init_alloc_root: enter: root: 0x62a0000bf5e0  prealloc: 1024

my_malloc: my: size: 1048  my_flags: 65536

my_malloc: info: thd memory_used: 22416  size: 1056

my_malloc: exit: ptr: 0x619000123488

init_alloc_root: enter: root: 0x62a0000bf378  prealloc: 0

safe_mutex_init: enter: mutex: 0x62a0000bbb50  name: &LOCK_thd_data

safe_mutex_init: enter: mutex: 0x62a0000bf700  name: &LOCK_wakeup_ready

safe_mutex_init: enter: mutex: 0x62a0000bbc00  name: &LOCK_thd_kill

handle_slave_io: mutex: LOCK_thread_count (0x34cf8e0) locking

handle_slave_io: mutex: LOCK_thread_count (0x34cf8e0) locked

handle_slave_io: mutex: LOCK_thd_data (0x62a0000bbb50) locking

my_malloc: my: size: 208  my_flags: 24

my_malloc: info: global thd memory_used: 0  size: 216

my_malloc: exit: ptr: 0x6110000818c8

my_hash_init: enter: hash:0x6110000818c8  size: 128

my_malloc: my: size: 2048  my_flags: 0

my_malloc: info: global thd memory_used: 216  size: 2056

my_malloc: exit: ptr: 0x61d00022ba88

my_hash_init: enter: hash:0x611000081930  size: 128

my_malloc: my: size: 2048  my_flags: 0

my_malloc: info: global thd memory_used: 2272  size: 2056

my_malloc: exit: ptr: 0x61d00022b088

my_malloc: my: size: 56  my_flags: 56

my_malloc: info: global thd memory_used: 4328  size: 64

my_malloc: exit: ptr: 0x6060000b38a8

add_to_locked_mutex: info: inserting 0x6060000b38a8  into  0x62a000093e60  (id: 279 -> 229)

add_to_locked_mutex: info: inserting 0x6060000b38a8  into  0x34cfb80  (id: 279 -> 5)

add_to_locked_mutex: info: inserting 0x6060000b38a8  into  0x62a000091d20  (id: 279 -> 226)

add_to_locked_mutex: info: inserting 0x6060000b38a8  into  0x62a0000923a8  (id: 279 -> 230)

add_to_locked_mutex: info: inserting 0x6060000b38a8  into  0x350b448  (id: 279 -> 43)

add_to_locked_mutex: info: inserting 0x6060000b38a8  into  0x62a000093f10  (id: 279 -> 236)

add_to_locked_mutex: info: inserting 0x6060000b38a8  into  0x34d0b40  (id: 279 -> 3)

add_to_locked_mutex: info: inserting 0x6060000b38a8  into  0x34cf8e0  (id: 279 -> 6)

handle_slave_io: mutex: LOCK_thd_data (0x62a0000bbb50) locked

handle_slave_io: mutex: LOCK_thd_data (0x62a0000bbb50) unlocking

handle_slave_io: mutex: LOCK_thread_count (0x34cf8e0) unlocking

thd::init: mutex: LOCK_global_system_variables (0x34d0280) locking

thd::init: mutex: LOCK_global_system_variables (0x34d0280) locked

my_free: my: ptr: 0x0

plugin_thdvar_init: mutex: LOCK_plugin (0x34da920) locking

my_hash_first_from_hash_value: exit: found key at 2

plugin_thdvar_init: mutex: LOCK_plugin (0x34da920) locked

my_malloc: my: size: 8  my_flags: 16

my_malloc: info: global thd memory_used: 4392  size: 16

my_malloc: exit: ptr: 0x60200001ebd8

intern_plugin_lock: lock: thd: 0x62a0000ba208  plugin: "MyISAM" LOCK ref_count: 45

plugin_thdvar_init: mutex: LOCK_plugin (0x34da920) unlocking

thd::init: mutex: LOCK_global_system_variables (0x34d0280) unlocking

reset_current_stmt_binlog_format_row: debug: temporary_tables: no, in_sub_stmt: no, system_thread: NON_SYSTEM_THREAD

my_malloc: my: size: 120  my_flags: 65584

my_malloc: info: thd memory_used: 23472  size: 128

my_malloc: exit: ptr: 0x60c000071b08

my_hash_init: enter: hash:0x60c000071a40  size: 4

my_malloc: my: size: 64  my_flags: 65536

my_malloc: info: thd memory_used: 23600  size: 72

my_malloc: exit: ptr: 0x60700003b358

my_hash_init: enter: hash:0x60c000071980  size: 4

my_malloc: my: size: 64  my_flags: 65536

my_malloc: info: thd memory_used: 23672  size: 72

my_malloc: exit: ptr: 0x60700003b2e8

thd::init: mutex: LOCK_plugin (0x34da920) locking

thd::init: mutex: LOCK_plugin (0x34da920) locked

thd::init: mutex: LOCK_plugin (0x34da920) unlocking

my_hash_free: enter: hash:0x60c000071a40  elements: 0

my_free: my: ptr: 0x60700003b358

my_free: info: thd memory_used: 23744  size: -72

my_hash_init: enter: hash:0x60c000071980  size: 4

my_malloc: my: size: 64  my_flags: 65536

my_malloc: info: thd memory_used: 23672  size: 72

my_malloc: exit: ptr: 0x60700003b278

my_hash_init: enter: hash:0x62a0000ba838  size: 16

my_malloc: my: size: 256  my_flags: 65536

my_malloc: info: thd memory_used: 23744  size: 264

my_malloc: exit: ptr: 0x6120000829c8

my_malloc: my: size: 128  my_flags: 0

my_malloc: info: global thd memory_used: 4408  size: 136

my_malloc: exit: ptr: 0x60d000047508

my_malloc: my: size: 1024  my_flags: 65552

my_malloc: info: thd memory_used: 24008  size: 1032

my_malloc: exit: ptr: 0x619000125288

handle_slave_io: mutex: run_lock (0x62a000091bc0) locking

handle_slave_io: mutex: run_lock (0x62a000091bc0) locked

handle_slave_io: mutex: err_lock (0x62a000090208) locking

handle_slave_io: mutex: err_lock (0x62a000090208) locked

handle_slave_io: mutex: err_lock (0x62a000090208) unlocking

my_net_init: enter: my_flags: 65536

my_net_set_read_timeout: enter: timeout: 30

my_net_set_write_timeout: enter: timeout: 60

my_malloc: my: size: 16392  my_flags: 65552

my_malloc: info: thd memory_used: 25040  size: 16400

my_malloc: exit: ptr: 0x62900018b208

init_slave_thread: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/slave.cc:3223

handle_slave_io: mutex: LOCK_thread_count (0x34cf8e0) locking

handle_slave_io: mutex: LOCK_thread_count (0x34cf8e0) locked

handle_slave_io: mutex: LOCK_thread_count (0x34cf8e0) unlocking

handle_slave_io: mutex: run_lock (0x62a000091bc0) unlocking

handle_slave_io: master_info: log_file_name: 'master-bin.000001'  position: 1597

rpl_load_gtid_slave_state: mutex: LOCK_slave_state (0x61300000d9a8) locking

rpl_load_gtid_slave_state: mutex: LOCK_slave_state (0x61300000d9a8) locked

rpl_load_gtid_slave_state: mutex: LOCK_slave_state (0x61300000d9a8) unlocking

start_slave_thread: mutex: run_lock (0x62a000091bc0) unlocking

start_slave_thread: mutex: var->mutex (0x61300015dec0) locking

my_hash_first_from_hash_value: exit: found key at 27

start_slave_thread: mutex: var->mutex (0x61300015dec0) locked

my_malloc: my: size: 1272  my_flags: 48

start_slave_thread: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/slave.cc:969

start_slave_thread: mutex: var->mutex (0x61300015dec0) unlocking

start_slave_thread: mutex: run_lock (0x62a000091bc0) locking

start_slave_thread: mutex: run_lock (0x62a000091bc0) locked

start_slave_thread: mutex: run_lock (0x62a000091bc0) unlocking

start_slave_thread: mutex: run_lock (0x62a000093f10) locking

my_hash_first_from_hash_value: exit: found key at 29

start_slave_thread: mutex: run_lock (0x62a000093f10) locked

start_slave_thread: info: Creating new slave thread

my_malloc: my: size: 488  my_flags: 16

my_malloc: info: global thd memory_used: 4544  size: 1280

my_malloc: exit: ptr: 0x61a00007ce88

handle_slave_io: mysql: mysql: 0x61a00007ce88

handle_slave_io: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/slave.cc:4333

my_malloc: info: global thd memory_used: 170376  size: 496

my_malloc: exit: ptr: 0x61500003f008

mysql_options: enter: option: 0

mysql_options: enter: option: 11

mysql_options: enter: option: 6001

mysql_options: enter: option: 7

my_free: my: ptr: 0x0

my_malloc: my: size: 7  my_flags: 16

my_malloc: info: global thd memory_used: 5824  size: 16

my_malloc: exit: ptr: 0x60200001eb58

mysql_options: enter: option: 6

my_free: my: ptr: 0x0

my_malloc: my: size: 66  my_flags: 16

start_slave_thread: sleep: Waiting for slave thread to start

start_slave_thread: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/slave.cc:960

my_malloc: info: global thd memory_used: 5840  size: 80

my_malloc: exit: ptr: 0x60700003b208

mysql_options: enter: option: 22

my_malloc: my: size: 160  my_flags: 48

my_malloc: info: global thd memory_used: 5920  size: 168

my_malloc: exit: ptr: 0x60f000006df8

my_malloc: my: size: 24  my_flags: 16

my_malloc: info: global thd memory_used: 6088  size: 32

my_malloc: exit: ptr: 0x60300006eb98

mysql_real_connect: enter: host: 127.0.0.1  db: (Null)  user: root (client)

mysql_options: enter: option: 34

mysql_options: enter: option: 34

mysql_options: enter: option: 34

mysql_options: enter: option: 34

mysql_options: enter: option: 34

mysql_options: enter: option: 34

mysql_option: enter: option: 33

my_hash_init: enter: hash:0x60f000006e28  size: 0

my_malloc: my: size: 64  my_flags: 16

my_malloc: info: global thd memory_used: 6120  size: 72

my_malloc: exit: ptr: 0x60700003b198

my_realloc: my: ptr: 0x0  size: 8176  my_flags: 80

safe_mutex_init: enter: mutex: 0x61d00027bab8  name: &LOCK_wait_commit

handle_slave_sql: mutex: LOCK_wait_commit (0x61d00027bab8) locking

my_malloc: my: size: 208  my_flags: 24

my_malloc: info: global memory_used: 16193296  size: 216

my_malloc: exit: ptr: 0x6110000935c8

my_hash_init: enter: hash:0x6110000935c8  size: 128

my_malloc: my: size: 2048  my_flags: 0

my_malloc: info: global memory_used: 16193512  size: 2056

my_malloc: exit: ptr: 0x61d00027b088

my_hash_init: enter: hash:0x611000093630  size: 128

my_malloc: my: size: 2048  my_flags: 0

my_malloc: info: global memory_used: 16195568  size: 2056

my_malloc: exit: ptr: 0x61d00027a688

handle_slave_sql: mutex: LOCK_wait_commit (0x61d00027bab8) locked

handle_slave_sql: mutex: LOCK_wait_commit (0x61d00027bab8) unlocking

safe_mutex_destroy: enter: mutex: 0x61d00027bab8  name: LOCK_wait_commit

my_hash_free: enter: hash:0x611000093630  elements: 0

my_malloc: my: size: 8176  my_flags: 80

my_malloc: info: global thd memory_used: 6192  size: 8184

my_malloc: exit: ptr: 0x6250001ba908

mysql_option: enter: option: 33

my_malloc: my: size: 56  my_flags: 16

my_malloc: info: global thd memory_used: 14376  size: 64

my_malloc: exit: ptr: 0x6060000b3848

mysql_option: enter: option: 33

my_malloc: my: size: 48  my_flags: 16

my_malloc: info: global thd memory_used: 14440  size: 56

my_malloc: exit: ptr: 0x6060000b37e8

mysql_option: enter: option: 33

my_malloc: my: size: 56  my_flags: 16

my_malloc: info: global thd memory_used: 14496  size: 64

my_malloc: exit: ptr: 0x6060000b3788

mysql_option: enter: option: 33

my_malloc: my: size: 48  my_flags: 16

my_malloc: info: global thd memory_used: 14560  size: 56

my_malloc: exit: ptr: 0x6060000b3728

mysql_real_connect: info: Connecting

mysql_real_connect: info: net->vio: 0x0  protocol: 0

mysql_real_connect: info: Server name: '127.0.0.1'.  TCP sock: 16040

mysql_real_connect: info: IP 'client'

mysql_real_connect: info: IPV6 getaddrinfo 127.0.0.1

mysql_real_connect: info: Try connect on all addresses for host.

mysql_real_connect: info: Create socket, family: 2  type: 1  proto: 6

vio_new: enter: sd: 70

mysql_socket_vio_new: enter: sd: 70

my_malloc: my: size: 496  my_flags: 16

my_malloc: info: global thd memory_used: 14616  size: 504

my_malloc: exit: ptr: 0x61500004f688

vio_init: enter: type: 1  sd: 70  flags: 2

my_malloc: my: size: 16384  my_flags: 16

my_malloc: info: global thd memory_used: 15120  size: 16392

my_malloc: exit: ptr: 0x6290001a4208

mysql_real_connect: info: Connect socket

vio_blocking: enter: set_blocking_mode: 0  old_mode: 1

vio_blocking: exit: 0

vio_io_wait: enter: timeout: 120000

vio_blocking: enter: set_blocking_mode: 1  old_mode: 0

vio_blocking: exit: 0

mysql_real_connect: info: End of connect attempts, sock: 70  status: 0  error: 0

mysql_real_connect: info: net->vio: 0x61500004f688

my_net_init: enter: my_flags: 0

my_net_set_read_timeout: enter: timeout: 30

my_net_set_write_timeout: enter: timeout: 60

my_malloc: my: size: 16392  my_flags: 16

my_malloc: info: global thd memory_used: 31512  size: 16400

my_malloc: exit: ptr: 0x62900019f208

vio_blocking: enter: set_blocking_mode: 0  old_mode: 1

vio_blocking: exit: 0

vio_fastsend: exit: 0

vio_keepalive: enter: sd: 70  set_keep_alive: 1

my_net_set_read_timeout: enter: timeout: 120

vio_io_wait: enter: timeout: 120000

mysql_real_connect: info: Read first packet.

vio_is_blocking: exit: 0

vio_read_buff: enter: sd: 70  buf: 0x62900019f208  size:4

vio_read: enter: sd: 70  buf: 0x6290001a4208  size: 16384

vio_read: read_data: Memory: 0x6290001a4208  Bytes: (103)

63 00 00 00 0A 35 2E 35 2E 35 2D 31 30 2E 32 2E 33 31 2D 4D 61 72 69 61 44 42

2D 64 65 62 75 67 2D 6C 6F 67 00 0C 00 00 00 42 49 2C 3D 2E 6B 55 49 00 FE FF

08 02 00 BF C1 15 00 00 00 00 00 00 07 00 00 00 4B 7C 50 5A 55 7B 2E 6D 5E 6E

2D 35 00 6D 79 73 71 6C 5F 6E 61 74 69 76 65 5F 70 61 73 73 77 6F 72 64 00

vio_read: exit: 103

mysql_real_connect: packet_header: Memory: 0x62900019f208  Bytes: (4)

63 00 00 00

vio_read_buff: enter: sd: 70  buf: 0x62900019f208  size:99

my_free: my: ptr: 0x61d00027a688

my_free: info: global memory_used: 16197624  size: -2056

my_hash_free: enter: hash:0x6110000935c8  elements: 0

my_free: my: ptr: 0x61d00027b088

my_free: info: global memory_used: 16195568  size: -2056

my_free: my: ptr: 0x6110000935c8

my_free: info: global memory_used: 16193512  size: -216

safe_mutex_init: enter: mutex: 0x61d00027bab8  name: &LOCK_wait_commit

my_hash_init: enter: hash:0x61d00027bc50  size: 32

my_malloc: my: size: 512  my_flags: 0

my_malloc: info: global memory_used: 16193296  size: 520

my_malloc: exit: ptr: 0x61600006e188

init_alloc_root: enter: root: 0x61d00027bc10  prealloc: 0

handle_slave_sql: mutex: LOCK_wait_commit (0x61d00027bab8) locking

my_malloc: my: size: 208  my_flags: 24

my_malloc: info: global memory_used: 16193816  size: 216

my_malloc: exit: ptr: 0x611000093488

my_hash_init: enter: hash:0x611000093488  size: 128

my_malloc: my: size: 2048  my_flags: 0

my_malloc: info: global memory_used: 16194032  size: 2056

my_malloc: exit: ptr: 0x61d000279c88

my_hash_init: enter: hash:0x6110000934f0  size: 128

my_malloc: my: size: 2048  my_flags: 0

my_malloc: info: global memory_used: 16196088  size: 2056

my_malloc: exit: ptr: 0x61d000279288

handle_slave_sql: mutex: LOCK_wait_commit (0x61d00027bab8) locked

handle_slave_sql: mutex: LOCK_wait_commit (0x61d00027bab8) unlocking

safe_mutex_destroy: enter: mutex: 0x61d00027bab8  name: LOCK_wait_commit

my_hash_free: enter: hash:0x6110000934f0  elements: 0

my_free: my: ptr: 0x61d000279288

my_free: info: global memory_used: 16198144  size: -2056

my_hash_free: enter: hash:0x611000093488  elements: 0

my_free: my: ptr: 0x61d000279c88

my_free: info: global memory_used: 16196088  size: -2056

my_free: my: ptr: 0x611000093488

my_free: info: global memory_used: 16194032  size: -216

safe_mutex_init: enter: mutex: 0x61d00027bab8  name: &LOCK_wait_commit

safe_mutex_init: enter: mutex: 0x61d00027bcb8  name: &sleep_lock

handle_slave_sql: mutex: LOCK_thread_id (0x34d0c20) locking

handle_slave_sql: mutex: LOCK_thread_id (0x34d0c20) locked

handle_slave_sql: mutex: LOCK_thread_id (0x34d0c20) unlocking

my_malloc: my: size: 22416  my_flags: 4120

my_malloc: info: global memory_used: 16193816  size: 22424

my_malloc: exit: ptr: 0x62a0000d2208

safe_mutex_init: enter: mutex: 0x62a0000d2328  name: &m_LOCK_wait_status

my_hash_init: enter: hash:0x62a0000d3cb0  size: 16

my_malloc: my: size: 256  my_flags: 0

my_malloc: info: global memory_used: 16216240  size: 264

my_malloc: exit: ptr: 0x612000099dc8

my_hash_init: enter: hash:0x62a0000d3d18  size: 16

my_malloc: my: size: 256  my_flags: 0

my_malloc: info: global memory_used: 16216504  size: 264

my_malloc: exit: ptr: 0x612000099c48

init_alloc_root: enter: root: 0x62a0000d5628  prealloc: 0

init_alloc_root: enter: root: 0x62a0000d5c70  prealloc: 0

mysql_real_connect: packet: Memory: 0x62900019f208  Bytes: (10)

0A 35 2E 35 2E 35 2D 31 30 2E

mysql_real_connect: info: mysql protocol version 10, server=10

init_alloc_root: enter: root: 0x62a0000d75e0  prealloc: 1024

my_malloc: my: size: 1048  my_flags: 65536

my_malloc: info: thd memory_used: 22416  size: 1056

my_malloc: exit: ptr: 0x619000123e88

init_alloc_root: enter: root: 0x62a0000d7378  prealloc: 0

get_charset_by_csname: enter: name: 'latin1'

safe_mutex_init: enter: mutex: 0x62a0000d3b50  name: &LOCK_thd_data

safe_mutex_init: enter: mutex: 0x62a0000d7700  name: &LOCK_wakeup_ready

safe_mutex_init: enter: mutex: 0x62a0000d3c00  name: &LOCK_thd_kill

my_malloc: my: size: 88  my_flags: 0

handle_slave_sql: mutex: LOCK_thread_count (0x34cf8e0) locking

handle_slave_sql: mutex: LOCK_thread_count (0x34cf8e0) locked

my_malloc: info: global thd memory_used: 47912  size: 96

handle_slave_sql: mutex: LOCK_thd_data (0x62a0000d3b50) locking

my_malloc: my: size: 208  my_flags: 24

my_malloc: info: global thd memory_used: 0  size: 216

my_malloc: exit: ptr: 0x611000093348

my_hash_init: enter: hash:0x611000093348  size: 128

my_malloc: my: size: 2048  my_flags: 0

my_malloc: exit: ptr: 0x608000013ea8

my_malloc: my: size: 5  my_flags: 0

my_malloc: info: global thd memory_used: 48008  size: 16

my_malloc: exit: ptr: 0x60200001eb38

my_malloc: info: global thd memory_used: 216  size: 2056

my_malloc: exit: ptr: 0x61d000278888

my_hash_init: enter: hash:0x6110000933b0  size: 128

my_malloc: my: size: 2048  my_flags: 0

my_malloc: my: size: 1  my_flags: 0

my_malloc: info: global thd memory_used: 2272  size: 2056

my_malloc: exit: ptr: 0x61d000277e88

my_malloc: info: global thd memory_used: 48024  size: 16

my_malloc: exit: ptr: 0x60200001eb18

run_plugin_auth: info: using plugin mysql_native_password

my_malloc: my: size: 56  my_flags: 56

my_malloc: info: global thd memory_used: 4328  size: 64

my_malloc: exit: ptr: 0x6060000afe88

add_to_locked_mutex: info: inserting 0x6060000afe88  into  0x62a000093e60  (id: 282 -> 229)

native_password_auth_client: info: no password

native_password_auth_client: info: Server version = '10.2.31-MariaDB-debug-log'  capabilites: 18446744072665169918  status: 2  client_flag: 2151195141

native_password_auth_client: info: user: root

native_password_auth_client: packet_header: Memory: 0x7f404c655650  Bytes: (4)

91 00 00 01

vio_is_blocking: exit: 0

vio_write: enter: sd: 70  buf: 0x62900019f208  size: 149

add_to_locked_mutex: info: inserting 0x6060000afe88  into  0x34cfb80  (id: 282 -> 5)

add_to_locked_mutex: info: inserting 0x6060000afe88  into  0x62a000091d20  (id: 282 -> 226)

add_to_locked_mutex: info: inserting 0x6060000afe88  into  0x62a0000923a8  (id: 282 -> 230)

add_to_locked_mutex: info: inserting 0x6060000afe88  into  0x350b448  (id: 282 -> 43)

add_to_locked_mutex: info: inserting 0x6060000afe88  into  0x62a000093f10  (id: 282 -> 236)

add_to_locked_mutex: info: inserting 0x6060000afe88  into  0x34d0b40  (id: 282 -> 3)

add_to_locked_mutex: info: inserting 0x6060000afe88  into  0x34cf8e0  (id: 282 -> 6)

handle_slave_sql: mutex: LOCK_thd_data (0x62a0000d3b50) locked

handle_slave_sql: mutex: LOCK_thd_data (0x62a0000d3b50) unlocking

handle_slave_sql: mutex: LOCK_thread_count (0x34cf8e0) unlocking

thd::init: mutex: LOCK_global_system_variables (0x34d0280) locking

thd::init: mutex: LOCK_global_system_variables (0x34d0280) locked

my_free: my: ptr: 0x0

plugin_thdvar_init: mutex: LOCK_plugin (0x34da920) locking

my_hash_first_from_hash_value: exit: found key at 2

plugin_thdvar_init: mutex: LOCK_plugin (0x34da920) locked

my_malloc: my: size: 8  my_flags: 16

my_malloc: info: global thd memory_used: 4392  size: 16

my_malloc: exit: ptr: 0x60200001d578

intern_plugin_lock: lock: thd: 0x62a0000d2208  plugin: "MyISAM" LOCK ref_count: 46

plugin_thdvar_init: mutex: LOCK_plugin (0x34da920) unlocking

thd::init: mutex: LOCK_global_system_variables (0x34d0280) unlocking

reset_current_stmt_binlog_format_row: debug: temporary_tables: no, in_sub_stmt: no, system_thread: NON_SYSTEM_THREAD

my_malloc: my: size: 120  my_flags: 65584

my_malloc: info: thd memory_used: 23472  size: 128

my_malloc: exit: ptr: 0x60c000089a48

my_hash_init: enter: hash:0x60c000089980  size: 4

my_malloc: my: size: 64  my_flags: 65536

my_malloc: info: thd memory_used: 23600  size: 72

my_malloc: exit: ptr: 0x607000037d18

my_hash_init: enter: hash:0x60c0000898c0  size: 4

my_malloc: my: size: 64  my_flags: 65536

my_malloc: info: thd memory_used: 23672  size: 72

my_malloc: exit: ptr: 0x607000037ca8

vio_write: exit: 149

run_plugin_auth: info: authenticate_user returned CR_OK

vio_is_blocking: exit: 0

vio_read_buff: enter: sd: 70  buf: 0x62900019f208  size:4

vio_read: enter: sd: 70  buf: 0x6290001a4208  size: 16384

thd::init: mutex: LOCK_plugin (0x34da920) locking

thd::init: mutex: LOCK_plugin (0x34da920) locked

thd::init: mutex: LOCK_plugin (0x34da920) unlocking

my_hash_free: enter: hash:0x60c000089980  elements: 0

my_free: my: ptr: 0x607000037d18

my_free: info: thd memory_used: 23744  size: -72

my_hash_init: enter: hash:0x60c0000898c0  size: 4

my_malloc: my: size: 64  my_flags: 65536

my_malloc: info: thd memory_used: 23672  size: 72

my_malloc: exit: ptr: 0x607000037c38

vio_read: read_data: Memory: 0x6290001a4208  Bytes: (11)

07 00 00 02 00 00 00 02 00 00 00

vio_read: exit: 11

run_plugin_auth: packet_header: Memory: 0x62900019f208  Bytes: (4)

07 00 00 02

vio_read_buff: enter: sd: 70  buf: 0x62900019f208  size:7

my_hash_init: enter: hash:0x62a0000d2838  size: 16

my_malloc: my: size: 256  my_flags: 65536

my_malloc: info: thd memory_used: 23744  size: 264

my_malloc: exit: ptr: 0x612000099ac8

my_malloc: my: size: 128  my_flags: 0

my_malloc: info: global thd memory_used: 4408  size: 136

my_malloc: exit: ptr: 0x60d00003ff38

run_plugin_auth: info: OK packet length=7

mysql_real_connect: exit: Mysql handler: 0x61a00007ce88

connect_to_master: mutex: err_lock (0x62a000090208) locking

my_malloc: my: size: 1024  my_flags: 65552

my_malloc: info: thd memory_used: 24008  size: 1032

my_malloc: exit: ptr: 0x619000132e88

handle_slave_sql: mutex: run_lock (0x62a000093f10) locking

handle_slave_sql: mutex: run_lock (0x62a000093f10) locked

connect_to_master: mutex: err_lock (0x62a000090208) locked

connect_to_master: mutex: err_lock (0x62a000090208) unlocking

connect_to_master: mutex: LOCK_rpl_status (0x34d76c0) locking

connect_to_master: mutex: LOCK_rpl_status (0x34d76c0) locked

my_net_init: enter: my_flags: 65536

my_net_set_read_timeout: enter: timeout: 30

my_net_set_write_timeout: enter: timeout: 60

my_malloc: my: size: 16392  my_flags: 65552

connect_to_master: mutex: LOCK_rpl_status (0x34d76c0) unlocking

my_malloc: info: thd memory_used: 25040  size: 16400

connect_to_master: mutex: LOCK_log (0x61e00000f088) locking

connect_to_master: mutex: LOCK_log (0x61e00000f088) locked

my_malloc: exit: ptr: 0x62900019a208

init_slave_thread: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/slave.cc:3221

my_b_flush_io_cache: enter: cache: 0x61e00000f418

my_write: my: fd: 18  Buffer: 0x625000032108  Count: 41  MyFlags: 532

ha_enable_transaction: enter: on: 1

ha_commit_trans: info: thd: 0x62a0000d2208  option_bits: 2147748608  all: 0

ha_commit_trans: info: all: 0  thd->in_sub_stmt: 0  ha_info: 0x0  is_real_trans: 1

free_root: enter: root: 0x62a0000d5628  flags: 1

my_malloc: my: size: 24600  my_flags: 65536

connect_to_master: mutex: LOCK_log (0x61e00000f088) unlocking

my_malloc: info: thd memory_used: 41440  size: 24608

connect_to_master: mutex: LOCK_thd_data (0x62a0000bbb50) locking

my_malloc: exit: ptr: 0x62b000046208

my_malloc: my: size: 4120  my_flags: 65536

connect_to_master: mutex: LOCK_thd_data (0x62a0000bbb50) locked

connect_to_master: mutex: LOCK_thd_data (0x62a0000bbb50) unlocking

connect_to_master: exit: slave_was_killed: 0

my_malloc: info: thd memory_used: 66048  size: 4128

my_malloc: exit: ptr: 0x6210000af108

print_buffer_to_file: enter: buffer: Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication started in log 'master-bin.000001' at position 1597

print_buffer_to_file: mutex: LOCK_error_log (0x34cfd40) locking

print_buffer_to_file: mutex: LOCK_error_log (0x34cfd40) locked

my_malloc: my: size: 256  my_flags: 0

2020-01-02  1:41:36 139914136352512 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication started in log 'master-bin.000001' at position 1597

my_malloc: info: global thd memory_used: 4544  size: 264

my_malloc: exit: ptr: 0x612000099948

handle_slave_sql: mutex: LOCK_thread_count (0x34cf8e0) locking

print_buffer_to_file: mutex: LOCK_error_log (0x34cfd40) unlocking

my_hash_first_from_hash_value: exit: found key at 10

handle_slave_sql: mutex: LOCK_thread_count (0x34cf8e0) locked

handle_slave_sql: mutex: LOCK_thread_count (0x34cf8e0) unlocking

handle_slave_sql: mutex: run_lock (0x62a000093f10) unlocking

handle_slave_io: mutex: run_lock (0x62a000091bc0) locking

handle_slave_io: mutex: run_lock (0x62a000091bc0) locked

handle_slave_io: mutex: run_lock (0x62a000091bc0) unlocking

start_slave_thread: mutex: run_lock (0x62a000093f10) unlocking

start_slave_thread: mutex: var->mutex (0x61300015dec0) locking

handle_slave_sql: mutex: err_lock (0x62a000091ed0) locking

handle_slave_sql: mutex: err_lock (0x62a000091ed0) locked

handle_slave_io: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/slave.cc:4395

my_malloc: my: size: 256  my_flags: 24

my_hash_first_from_hash_value: exit: found key at 27

start_slave_thread: mutex: var->mutex (0x61300015dec0) locked

handle_slave_sql: mutex: err_lock (0x62a000091ed0) unlocking

my_hash_reset: enter: hash:0x62a000095140

init_relay_log_pos: info: pos: 556

init_relay_log_pos: mutex: data_lock (0x62a000093e60) locking

init_relay_log_pos: mutex: data_lock (0x62a000093e60) locked

my_malloc: my: size: 256  my_flags: 24

my_malloc: info: global thd memory_used: 4808  size: 264

my_malloc: exit: ptr: 0x6120000997c8

my_malloc: my: size: 14  my_flags: 0

my_malloc: info: global thd memory_used: 48040  size: 264

my_malloc: exit: ptr: 0x612000082848

start_slave_thread: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/slave.cc:969

my_malloc: info: global thd memory_used: 5072  size: 24

start_slave_thread: mutex: var->mutex (0x61300015dec0) unlocking

start_slave_thread: mutex: run_lock (0x62a000093f10) locking

my_hash_first_from_hash_value: exit: found key at 29

my_malloc: exit: ptr: 0x60300006d038

my_malloc: my: size: 172  my_flags: 0

init_relay_log_pos: info: Format_description_log_event::server_version_split: '4.0' 4 0 0

init_relay_log_pos: mutex: LOCK_log (0x62a0000923a8) locking

my_hash_first_from_hash_value: exit: found key at 23

init_relay_log_pos: mutex: LOCK_log (0x62a0000923a8) locked

find_log_pos: mutex: LOCK_index (0x62a0000928d8) locking

start_slave_thread: mutex: run_lock (0x62a000093f10) locked

start_slave_thread: mutex: run_lock (0x62a000093f10) unlocking

find_log_pos: mutex: LOCK_index (0x62a0000928d8) locked

find_log_pos: enter: log_name: NULL, full_log_name:

reinit_io_cache: enter: cache:0x62a000092b60 type: 1  seek_offset: 0  clear_cache: 0

my_malloc: info: global thd memory_used: 48304  size: 184

my_malloc: exit: ptr: 0x61000000f948

get_master_version_and_clock: info: Format_description_log_event::server_version_split: '10.2.31-MariaDB-debug-log' 10 2 31

dirname_part: enter: 'slave-relay-bin'

dirname_part: enter: './slave-relay-bin.000002'

find_log_pos: info: Found log file entry

find_log_pos: mutex: LOCK_index (0x62a0000928d8) unlocking

find_log_pos: mutex: LOCK_index (0x62a0000928d8) locking

find_log_pos: mutex: LOCK_index (0x62a0000928d8) locked

dirname_part: enter: 'slave-relay-bin'

dirname_part: enter: './slave-relay-bin.000003'

find_log_pos: enter: log_name: ./slave-relay-bin.000003, full_log_name: ./slave-relay-bin.000003

reinit_io_cache: enter: cache:0x62a000092b60 type: 1  seek_offset: 0  clear_cache: 0

dirname_part: enter: 'slave-relay-bin'

dirname_part: enter: './slave-relay-bin.000002'

dirname_part: enter: 'slave-relay-bin'

dirname_part: enter: './slave-relay-bin.000003'

find_log_pos: info: Found log file entry

find_log_pos: mutex: LOCK_index (0x62a0000928d8) unlocking

my_b_seek: enter: pos: 0

my_b_flush_io_cache: enter: cache: 0x62a000092738

my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000092788) locking

my_hash_first_from_hash_value: exit: found key at 23

my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000092788) locked

my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000092788) unlocking

mysql_real_query: enter: handle: 0x61a00007ce88

mysql_real_query: query: Query = 'SELECT UNIX_TIMESTAMP()'

net_write_command: enter: length: 23

init_relay_log_pos: mutex: info->append_buffer_lock (0x62a000092788) locking

my_hash_first_from_hash_value: exit: found key at 23

init_relay_log_pos: mutex: info->append_buffer_lock (0x62a000092788) locked

unlock_slave_threads: mutex: start_stop_lock (0x62a000091d20) unlocking

my_seek: my: fd: 80 Pos: 0  Whence: 0  MyFlags: 0

my_read: my: fd: 80  Buffer: 0x629000190208  Count: 1012  MyFlags: 560

start_slave: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/sql_repl.cc:3158

vio_is_blocking: exit: 0

vio_write: enter: sd: 70  buf: 0x62900019f208  size: 28

init_relay_log_pos: mutex: info->append_buffer_lock (0x62a000092788) unlocking

my_malloc: my: size: 256  my_flags: 24

my_malloc: info: global thd memory_used: 5096  size: 264

my_malloc: exit: ptr: 0x612000099648

my_malloc: my: size: 14  my_flags: 0

mysql_execute_command: mutex: sleep_lock (0x62a000091c70) locking

mysql_execute_command: mutex: sleep_lock (0x62a000091c70) locked

my_malloc: info: global thd memory_used: 5360  size: 24

my_malloc: exit: ptr: 0x60300006d008

init_relay_log_pos: info: Format_description_log_event::server_version_split: '4.0' 4 0 0

init_relay_log_pos: info: looking for a Format_description_log_event

my_malloc: my: size: 152  my_flags: 16

my_malloc: info: global thd memory_used: 5384  size: 160

my_malloc: exit: ptr: 0x60e00001a0c8

my_realloc: my: ptr: 0x60e00001a0c8  size: 640  my_flags: 16

mysql_execute_command: mutex: sleep_lock (0x62a000091c70) unlocking

mysql_execute_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/sql_parse.cc:5982

my_realloc: info: global thd memory_used: 5544  size: 488

vio_write: exit: 28

my_realloc: exit: ptr: 0x61700004de88

Log_event::read_log_event(char*,...): info: binlog_version: 3

Log_event::read_log_event(char*,...): data: header: timestamp:1577947296 type:15 server_id:2 len:252 log_pos:256 flags:262144

Log_event::read_log_event(char*,...): data: Memory: 0x61700004de9b  Bytes: (233)

04 00 31 30 2E 32 2E 33 31 2D 4D 61 72 69 61 44 42 2D 64 65 62 75 67 2D 6C 6F

67 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 13 38 0D 00 08 00 12 00 04 04 04 04 12 00 00 E4 00 04 1A 08 00 00

00 08 08 08 02 00 00 00 0A 0A 0A 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 04 13 04 00 0D 08 08 08 0A 0A 0A 01 A6 78 0C 3A

Log_event::read_log_event(char*,...): info: crc: 973895846

my_malloc: my: size: 256  my_flags: 24

my_malloc: info: global thd memory_used: 6032  size: 264

my_malloc: exit: ptr: 0x6120000994c8

Log_event::read_log_event(char*,...): info: log_pos: 256

Format_description_log_event::Format_description_log_event(char*,...): info: common_header_len=19 number_of_event_types=172

my_malloc: my: size: 172  my_flags: 0

close_thread_tables: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/sql_base.cc:725

debug_sync: debug_sync_point: hit: 'before_close_thread_tables'

my_malloc: info: global thd memory_used: 6296  size: 184

my_malloc: exit: ptr: 0x610000027848

Format_description_log_event::Format_description_log_event(char*,...): info: Format_description_log_event::server_version_split: '10.2.31-MariaDB-debug-log' 10 2 31

Log_event::read_log_event(char*,...): read_event: Format_desc(type_code: 15; event_len: 248)

init_relay_log_pos: info: found Format_description_log_event

my_free: my: ptr: 0x60300006d008

my_free: info: global thd memory_used: 6480  size: -24

cli_advanced_command: exit: result: 0

my_free: my: ptr: 0x612000099648

my_free: info: global thd memory_used: 6456  size: -264

init_relay_log_pos: info: looking for a Format_description_log_event

my_malloc: my: size: 152  my_flags: 16

vio_is_blocking: exit: 0

vio_read_buff: enter: sd: 70  buf: 0x62900019f208  size:4

vio_read: enter: sd: 70  buf: 0x6290001a4208  size: 16384

vio_read: read_data: Memory: 0x6290001a4208  Bytes: (80)

01 00 00 01 01 26 00 00 02 03 64 65 66 00 00 00 10 55 4E 49 58 5F 54 49 4D 45

53 54 41 4D 50 28 29 00 0C 3F 00 11 00 00 00 08 80 00 00 00 00 05 00 00 03 FE

00 00 02 00 0B 00 00 04 0A 31 35 37 37 39 34 37 32 39 36 05 00 00 05 FE 00 00

02 00

vio_read: exit: 80

cli_read_query_result: packet_header: Memory: 0x62900019f208  Bytes: (4)

01 00 00 01

debug_sync: debug_sync_point: hit: 'execute_command_after_close_tables'

mysql_parse: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/sql_parse.cc:7757

vio_read_buff: enter: sd: 70  buf: 0x62900019f208  size:1

my_malloc: info: global thd memory_used: 6192  size: 160

my_malloc: exit: ptr: 0x60e000019fe8

Log_event::read_log_event(char*,...): info: binlog_version: 4

Log_event::read_log_event(char*,...): data: header: timestamp:0 type:4 server_id:1 len:48 log_pos:0 flags:74776608

Log_event::read_log_event(char*,...): data: Memory: 0x60e000019ffb  Bytes: (29)

75 04 00 00 00 00 00 00 6D 61 73 74 65 72 2D 62 69 6E 2E 30 30 30 30 30 31 A2

55 68 11

Log_event::read_log_event(char*,...): info: crc: 292050338

my_malloc: my: size: 128  my_flags: 24

my_malloc: info: global thd memory_used: 6352  size: 136

my_malloc: exit: ptr: 0x60d00003fe68

Log_event::read_log_event(char*,...): info: log_pos: 0

my_malloc: my: size: 18  my_flags: 16

my_malloc: info: global thd memory_used: 6488  size: 32

my_malloc: exit: ptr: 0x60300006cfd8

Rotate_log_event::Rotate_log_event(char*,...): debug: new_log_ident: 'master-bin.000001'

Log_event::read_log_event(char*,...): read_event: Rotate(type_code: 4; event_len: 44)

init_relay_log_pos: info: found event of another type=4

my_free: my: ptr: 0x60300006cfd8

my_free: info: global thd memory_used: 6520  size: -32

my_free: my: ptr: 0x60e000019fe8

my_free: info: global thd memory_used: 6488  size: -160

my_free: my: ptr: 0x60d00003fe68

my_free: info: global thd memory_used: 6328  size: -136

init_relay_log_pos: info: looking for a Format_description_log_event

my_malloc: my: size: 152  my_flags: 16

my_malloc: info: global thd memory_used: 6192  size: 160

my_malloc: exit: ptr: 0x60e000019f08

my_realloc: my: ptr: 0x60e000019f08  size: 640  my_flags: 16

init_alloc_root: enter: root: 0x61a00007d188  prealloc: 0

vio_is_blocking: exit: 0

vio_read_buff: enter: sd: 70  buf: 0x62900019f208  size:4

cli_read_rows: packet_header: Memory: 0x62900019f208  Bytes: (4)

26 00 00 02

vio_read_buff: enter: sd: 70  buf: 0x62900019f208  size:38

my_malloc: my: size: 96  my_flags: 48

lex_end: enter: lex: 0x62a0000b7d40

dispatch_command: info: query ready

my_realloc: info: global thd memory_used: 6352  size: 488

my_realloc: exit: ptr: 0x61700004db08

Log_event::read_log_event(char*,...): info: binlog_version: 4

Log_event::read_log_event(char*,...): data: header: timestamp:1577947295 type:15 server_id:1 len:252 log_pos:0 flags:262144

Log_event::read_log_event(char*,...): data: Memory: 0x61700004db1b  Bytes: (233)

04 00 31 30 2E 32 2E 33 31 2D 4D 61 72 69 61 44 42 2D 64 65 62 75 67 2D 6C 6F

67 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 13 38 0D 00 08 00 12 00 04 04 04 04 12 00 00 E4 00 04 1A 08 00 00

00 08 08 08 02 00 00 00 0A 0A 0A 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00

00 00 00 00 00 00 00 00 00 04 13 04 00 0D 08 08 08 0A 0A 0A 01 F9 CC C5 97

Log_event::read_log_event(char*,...): info: crc: 2546322681

my_malloc: my: size: 256  my_flags: 24

my_malloc: info: global thd memory_used: 6840  size: 264

my_malloc: exit: ptr: 0x612000099348

my_malloc: info: global thd memory_used: 48488  size: 104

dispatch_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/sql_parse.cc:2383

net_send_ok: info: affected_rows: 0  id: 0  status: 2  warning_count: 0

my_malloc: exit: ptr: 0x60b0000c0798

init_alloc_root: enter: root: 0x60b0000c07a8  prealloc: 0

alloc_root: enter: root: 0x60b0000c07a8

my_malloc: my: size: 8152  my_flags: 69648

Log_event::read_log_event(char*,...): info: log_pos: 0

my_malloc: info: thd memory_used: 41440  size: 8160

net_send_ok: packet_header: Memory: 0x7f404c540b60  Bytes: (4)

07 00 00 01

vio_is_blocking: exit: 0

my_malloc: exit: ptr: 0x6250001b8108

Format_description_log_event::Format_description_log_event(char*,...): info: common_header_len=19 number_of_event_types=172

my_malloc: my: size: 172  my_flags: 0

my_malloc: info: global thd memory_used: 7104  size: 184

my_malloc: exit: ptr: 0x610000027748

Format_description_log_event::Format_description_log_event(char*,...): info: Format_description_log_event::server_version_split: '10.2.31-MariaDB-debug-log' 10 2 31

Log_event::read_log_event(char*,...): read_event: Format_desc(type_code: 15; event_len: 248)

init_relay_log_pos: info: found Format_description_log_event

my_free: my: ptr: 0x610000027848

my_free: info: global thd memory_used: 7288  size: -184

my_free: my: ptr: 0x61700004de88

my_free: info: global thd memory_used: 7104  size: -648

alloc_root: exit: ptr: 0x6250001b8128

alloc_root: enter: root: 0x60b0000c07a8

alloc_root: exit: ptr: 0x6250001b8148

vio_is_blocking: exit: 0

vio_read_buff: enter: sd: 70  buf: 0x62900019f208  size:4

cli_read_rows: packet_header: Memory: 0x62900019f208  Bytes: (4)

05 00 00 03

vio_read_buff: enter: sd: 70  buf: 0x62900019f208  size:5

cli_read_rows: info: status: 2  warning_count:  0

cli_read_rows: exit: Got 1 rows

alloc_root: enter: root: 0x61a00007d188

my_malloc: my: size: 8152  my_flags: 69648

my_free: my: ptr: 0x6120000994c8

my_malloc: info: thd memory_used: 49600  size: 8160

my_malloc: exit: ptr: 0x6250001b5908

vio_write: enter: sd: 71  buf: 0x629000172208  size: 11

my_free: info: global thd memory_used: 6456  size: -264

init_relay_log_pos: info: looking for a Format_description_log_event

my_free: my: ptr: 0x60300006d038

my_free: info: global thd memory_used: 6192  size: -24

my_free: my: ptr: 0x6120000997c8

my_free: info: global thd memory_used: 6168  size: -264

my_b_seek: enter: pos: 556

my_b_flush_io_cache: enter: cache: 0x62a000092738

my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000092788) locking

my_hash_first_from_hash_value: exit: found key at 23

my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000092788) locked

my_b_flush_io_cache: mutex: info->append_buffer_lock (0x62a000092788) unlocking

init_relay_log_pos: info: my_b_tell(rli->cur_log)=556 rli->event_relay_log_pos=556

init_relay_log_pos: mutex: LOCK_log (0x62a0000923a8) unlocking

init_relay_log_pos: mutex: data_lock (0x62a000093e60) unlocking

init_relay_log_pos: info: Returning 0 from init_relay_log_pos

my_malloc: my: size: 568  my_flags: 48

my_malloc: info: global thd memory_used: 5904  size: 576

my_malloc: exit: ptr: 0x61600006de88

handle_slave_sql: mutex: LOCK_binlog_state (0x62a000095220) locking

handle_slave_sql: mutex: LOCK_binlog_state (0x62a000095220) locked

handle_slave_sql: mutex: LOCK_binlog_state (0x62a000095220) unlocking

my_malloc: my: size: 0  my_flags: 16

my_malloc: info: global thd memory_used: 6480  size: 16

my_malloc: exit: ptr: 0x60200001d4f8

handle_slave_sql: mutex: LOCK_binlog_state (0x62a000095220) locking

handle_slave_sql: mutex: LOCK_binlog_state (0x62a000095220) locked

handle_slave_sql: mutex: LOCK_binlog_state (0x62a000095220) unlocking

handle_slave_sql: info: my_b_tell(rli->cur_log)=556 rli->event_relay_log_pos=556

handle_slave_sql: master_info: log_file_name: master-bin.000001  position: 1141

print_buffer_to_file: enter: buffer: Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 1141, relay log './slave-relay-bin.000003' position: 556

print_buffer_to_file: mutex: LOCK_error_log (0x34cfd40) locking

print_buffer_to_file: mutex: LOCK_error_log (0x34cfd40) locked

2020-01-02  1:41:36 139914135820032 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 1141, relay log './slave-relay-bin.000003' position: 556

print_buffer_to_file: mutex: LOCK_error_log (0x34cfd40) unlocking

check_temp_dir: mutex: LOCK_start_thread (0x34cf9c0) locking

check_temp_dir: mutex: LOCK_start_thread (0x34cf9c0) locked

check_temp_dir: mutex: LOCK_start_thread (0x34cf9c0) unlocking

rpl_load_gtid_slave_state: mutex: LOCK_slave_state (0x61300000d9a8) locking

rpl_load_gtid_slave_state: mutex: LOCK_slave_state (0x61300000d9a8) locked

rpl_load_gtid_slave_state: mutex: LOCK_slave_state (0x61300000d9a8) unlocking

handle_slave_sql: mutex: data_lock (0x62a000093e60) locking

handle_slave_sql: mutex: data_lock (0x62a000093e60) locked

handle_slave_sql: mutex: data_lock (0x62a000093e60) unlocking

handle_slave_sql: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/slave.cc:5131

exec_relay_log_event: mutex: data_lock (0x62a000093e60) locking

exec_relay_log_event: mutex: data_lock (0x62a000093e60) locked

next_event: mutex: LOCK_log (0x62a0000923a8) locking

my_hash_first_from_hash_value: exit: found key at 23

next_event: mutex: LOCK_log (0x62a0000923a8) locked

next_event: info: my_b_tell(cur_log)=556 rli->event_relay_log_pos=556

my_malloc: my: size: 152  my_flags: 16

my_malloc: info: global thd memory_used: 6496  size: 160

my_malloc: exit: ptr: 0x60e000019e28

Log_event::read_log_event(char*,...): info: binlog_version: 4

Log_event::read_log_event(char*,...): data: header: timestamp:1577947296 type:162 server_id:1 len:42 log_pos:1183 flags:327688

Log_event::read_log_event(char*,...): data: Memory: 0x60e000019e3b  Bytes: (23)

05 00 00 00 00 00 00 00 00 00 00 00 08 00 00 00 00 00 00 3B 7F FE 1A

Log_event::read_log_event(char*,...): info: crc: 452886331

my_malloc: my: size: 128  my_flags: 24

my_malloc: info: global thd memory_used: 6656  size: 136

my_malloc: exit: ptr: 0x60d00003fd98

Log_event::read_log_event(char*,...): info: log_pos: 1183

Log_event::read_log_event(char*,...): read_event: Gtid(type_code: 162; event_len: 38)

next_event: mutex: LOCK_log (0x62a0000923a8) unlocking

exec_relay_log_event: info: event: 162  IN_STMT: 0  IN_TRANSACTION: 1

exec_relay_log_event: mutex: LOCK_slave_state (0x61300000d9a8) locking

my_hash_first_from_hash_value: exit: found key at 7

exec_relay_log_event: mutex: LOCK_slave_state (0x61300000d9a8) locked

exec_relay_log_event: mutex: LOCK_slave_state (0x61300000d9a8) unlocking

apply_event_and_update_pos_setup: exec_event: Gtid(type_code: 162; server_id: 1)

apply_event_and_update_pos_setup: info: thd->options: ''  rgi->last_event_start_time: 0

apply_event_and_update_pos_setup: info: ev->server_id: 1, ::server_id: 2, rli->replicate_same_server_id: 0, rli->slave_skip_counter: 0

sql_delay_event: mutex: data_lock (0x62a000093e60) unlocking

apply_event_and_update_pos_apply: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/log_event.h:1451

THD::reset_for_next_command: info: Lex and stmt_lex: 0x62a0000d5d40

reset_current_stmt_binlog_format_row: debug: temporary_tables: no, in_sub_stmt: no, system_thread: SYSTEM_THREAD_SLAVE_SQL

THD::reset_for_next_command: debug: is_current_stmt_binlog_format_row(): 1

apply_event_and_update_pos_apply: info: Set OPTION_GTID_BEGIN

apply_event_and_update_pos_apply: mutex: LOCK_thd_data (0x62a0000d3b50) locking

apply_event_and_update_pos_apply: mutex: LOCK_thd_data (0x62a0000d3b50) locked

apply_event_and_update_pos_apply: mutex: LOCK_thd_data (0x62a0000d3b50) unlocking

trans_begin: info: setting SERVER_STATUS_IN_TRANS

apply_event_and_update_pos_apply: mutex: LOCK_log (0x61e00000f088) locking

apply_event_and_update_pos_apply: mutex: LOCK_log (0x61e00000f088) locked

my_b_flush_io_cache: enter: cache: 0x61e00000f418

my_write: my: fd: 18  Buffer: 0x625000032108  Count: 20  MyFlags: 532

apply_event_and_update_pos_apply: mutex: LOCK_log (0x61e00000f088) unlocking

apply_event_and_update_pos_apply: mutex: LOCK_thd_data (0x62a0000d3b50) locking

apply_event_and_update_pos_apply: mutex: LOCK_thd_data (0x62a0000d3b50) locked

apply_event_and_update_pos_apply: mutex: LOCK_thd_data (0x62a0000d3b50) unlocking

free_root: enter: root: 0x62a0000d7378  flags: 1

apply_event_and_update_pos_apply: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/log_event.h:1453

apply_event_and_update_pos_apply: info: OPTION_BEGIN: 1  IN_STMT: 0  IN_TRANSACTION: 1

apply_event_and_update_pos_apply: skip_event: Gtid event was not skipped

apply_event_and_update_pos_apply: info: apply_event error = 0

apply_event_and_update_pos_apply: info: update_pos error = 0

apply_event_and_update_pos_apply: info: group 556 ./slave-relay-bin.000003

apply_event_and_update_pos_apply: info: event 598 ./slave-relay-bin.000003

exec_relay_log_event: info: Deleting the event after it has been executed

my_free: my: ptr: 0x60e000019e28

my_free: info: global thd memory_used: 6792  size: -160

my_free: my: ptr: 0x60d00003fd98

my_free: info: global thd memory_used: 6632  size: -136

exec_relay_log_event: mutex: LOCK_thd_data (0x62a0000d3b50) locking

exec_relay_log_event: mutex: LOCK_thd_data (0x62a0000d3b50) locked

exec_relay_log_event: mutex: LOCK_thd_data (0x62a0000d3b50) unlocking

handle_slave_sql: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/slave.cc:5131

exec_relay_log_event: mutex: data_lock (0x62a000093e60) locking

exec_relay_log_event: mutex: data_lock (0x62a000093e60) locked

next_event: mutex: LOCK_log (0x62a0000923a8) locking

my_hash_first_from_hash_value: exit: found key at 23

next_event: mutex: LOCK_log (0x62a0000923a8) locked

next_event: info: my_b_tell(cur_log)=598 rli->event_relay_log_pos=598

my_malloc: my: size: 152  my_flags: 16

my_malloc: info: global thd memory_used: 6496  size: 160

my_malloc: exit: ptr: 0x60e000019d48

Log_event::read_log_event(char*,...): info: binlog_version: 4

Log_event::read_log_event(char*,...): data: header: timestamp:1577947296 type:160 server_id:1 len:136 log_pos:1319 flags:1347747840

Log_event::read_log_event(char*,...): data: Memory: 0x60e000019d5b  Bytes: (117)

55 50 44 41 54 45 20 74 31 5F 31 31 37 35 33 30 30 34 2C 20 74 32 5F 31 31 37

35 33 30 30 34 20 53 45 54 20 74 31 5F 31 31 37 35 33 30 30 34 2E 63 31 3D 33

2C 20 74 32 5F 31 31 37 35 33 30 30 34 2E 63 31 3D 34 20 57 48 45 52 45 20 74

31 5F 31 31 37 35 33 30 30 34 2E 63 31 3D 31 20 4F 52 20 74 32 5F 31 31 37 35

33 30 30 34 2E 63 31 3D 32 2D 92 CB 9D

Log_event::read_log_event(char*,...): info: crc: 2647364141

my_malloc: my: size: 136  my_flags: 24

my_malloc: info: global thd memory_used: 6656  size: 144

my_malloc: exit: ptr: 0x60d00003fcc8

Log_event::read_log_event(char*,...): info: log_pos: 1319

Log_event::read_log_event(char*,...): read_event: Annotate_rows(type_code: 160; event_len: 132)

next_event: mutex: LOCK_log (0x62a0000923a8) unlocking

exec_relay_log_event: info: event: 160  IN_STMT: 1  IN_TRANSACTION: 1

apply_event_and_update_pos_setup: exec_event: Annotate_rows(type_code: 160; server_id: 1)

apply_event_and_update_pos_setup: info: thd->options: 'OPTION_BEGIN OPTION_GTID_BEGIN '  rgi->last_event_start_time: 0

apply_event_and_update_pos_setup: info: ev->server_id: 1, ::server_id: 2, rli->replicate_same_server_id: 0, rli->slave_skip_counter: 0

sql_delay_event: mutex: data_lock (0x62a000093e60) unlocking

apply_event_and_update_pos_apply: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/log_event.h:1451

apply_event_and_update_pos_apply: mutex: LOCK_thd_data (0x62a0000d3b50) locking

apply_event_and_update_pos_apply: mutex: LOCK_thd_data (0x62a0000d3b50) locked

apply_event_and_update_pos_apply: mutex: LOCK_thd_data (0x62a0000d3b50) unlocking

apply_event_and_update_pos_apply: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/log_event.h:1453

apply_event_and_update_pos_apply: info: OPTION_BEGIN: 1  IN_STMT: 1  IN_TRANSACTION: 1

apply_event_and_update_pos_apply: skip_event: Annotate_rows event was not skipped

apply_event_and_update_pos_apply: info: apply_event error = 0

apply_event_and_update_pos_apply: info: update_pos error = 0

apply_event_and_update_pos_apply: info: group 556 ./slave-relay-bin.000003

apply_event_and_update_pos_apply: info: event 734 ./slave-relay-bin.000003

exec_relay_log_event: mutex: LOCK_thd_data (0x62a0000d3b50) locking

exec_relay_log_event: mutex: LOCK_thd_data (0x62a0000d3b50) locked

exec_relay_log_event: mutex: LOCK_thd_data (0x62a0000d3b50) unlocking

handle_slave_sql: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.31/sql/slave.cc:5131

exec_relay_log_event: mutex: data_lock (0x62a000093e60) locking

exec_relay_log_event: mutex: data_lock (0x62a000093e60) locked

next_event: mutex: LOCK_log (0x62a0000923a8) locking

my_hash_first_from_hash_value: exit: found key at 23

nex

10.2 e40ed0e881690ed072c28c0f4080a3cf
binlog_encryption.rpl_incident 'mix' w4 [ fail ]
Test ended at 2020-04-12 12:32:19

CURRENT_TEST: binlog_encryption.rpl_incident
mysqltest: In included file "./extra/rpl_tests/rpl_incident.inc":
included from /home/buildbot/buildbot/build/mariadb-10.2.32/mysql-test/suite/binlog_encryption/rpl_incident.test at line 2:
At line 32: query 'set @@global.debug_dbug = @saved_dbug' failed: 2013: Lost connection to MySQL server during query

The result from queries just before the failure was:
< snip >
SET GLOBAL BINLOG_CHECKSUM=none;
connection master;
** On Master **
CREATE TABLE t1 (a INT);
INSERT INTO t1 VALUES (1),(2),(3);
SELECT * FROM t1;
a
1
2
3
set @saved_dbug = @@global.debug_dbug;
SET GLOBAL debug_dbug= '+d,incident_database_resync_on_replace,*';
REPLACE INTO t1 VALUES (4);
SELECT * FROM t1;
a
1
2
3
4
set @@global.debug_dbug = @saved_dbug;

More results from queries before failure can be found in /dev/shm/var/4/log/rpl_incident.log


Server [mysqld.1 - pid: 12396, winpid: 12396, exit: 256] failed during test run
Server log from this test:
----------SERVER LOG START-----------
2020-04-12 12:32:16 140532352559040 [Note] /home/buildbot/buildbot/build/mariadb-10.2.32/sql/mysqld (mysqld 10.2.32-MariaDB-debug-log) starting as process 12397 ...
2020-04-12 12:32:16 140532352559040 [Warning] Could not increase number of max_open_files to more than 1024 (request: 32186)
2020-04-12 12:32:16 140532352559040 [Warning] Changed limits: max_open_files: 1024 max_connections: 151 (was 151) table_cache: 421 (was 2000)
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'SEQUENCE' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'partition' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!
2020-04-12 12:32:16 140532352559040 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins
2020-04-12 12:32:16 140532352559040 [Note] InnoDB: Uses event mutexes
2020-04-12 12:32:16 140532352559040 [Note] InnoDB: Compressed tables use zlib 1.2.11
2020-04-12 12:32:16 140532352559040 [Note] InnoDB: Using Linux native AIO
2020-04-12 12:32:16 140532352559040 [Note] InnoDB: Number of pools: 1
2020-04-12 12:32:16 140532352559040 [Note] InnoDB: Using generic crc32 instructions
2020-04-12 12:32:16 140532352559040 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M
2020-04-12 12:32:16 140532352559040 [Note] InnoDB: Completed initialization of buffer pool
2020-04-12 12:32:16 140532149692160 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().
2020-04-12 12:32:16 140532352559040 [Note] InnoDB: Highest supported file format is Barracuda.
2020-04-12 12:32:16 140532352559040 [Note] InnoDB: 128 out of 128 rollback segments are active.
2020-04-12 12:32:16 140532352559040 [Note] InnoDB: Creating shared tablespace for temporary tables
2020-04-12 12:32:16 140532352559040 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...
2020-04-12 12:32:16 140532352559040 [Note] InnoDB: File './ibtmp1' size is now 12 MB.
2020-04-12 12:32:16 140532352559040 [Note] InnoDB: 5.7.29 started; log sequence number 1628840
2020-04-12 12:32:16 140532053759744 [Note] InnoDB: Loading buffer pool(s) from /dev/shm/var/4/mysqld.1/data/ib_buffer_pool
2020-04-12 12:32:16 140532053759744 [Note] InnoDB: Buffer pool(s) load completed at 200412 12:32:16
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_LOCKS' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_MUTEXES' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_CMPMEM' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_CMP_PER_INDEX' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_CMP' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_FT_DELETED' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_CMP_RESET' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_BUFFER_PAGE_LRU' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_SYS_FIELDS' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'FEEDBACK' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_SYS_COLUMNS' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'user_variables' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_SYS_FOREIGN_COLS' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_BUFFER_POOL_STATS' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_TRX' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_SYS_FOREIGN' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_SYS_TABLES' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_BUFFER_PAGE' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_METRICS' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_SYS_INDEXES' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_SYS_VIRTUAL' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.
2020-04-12 12:32:16 140532352559040 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.
2020-04-12 12:32:16 140532352559040 [Warning] /home/buildbot/buildbot/build/mariadb-10.2.32/sql/mysqld: unknown option '--loose-pam-debug'
2020-04-12 12:32:16 140532352559040 [Note] Server socket created on IP: '127.0.0.1'.
2020-04-12 12:32:16 140532352559040 [Note] Reading of all Master_info entries succeeded
2020-04-12 12:32:16 140532352559040 [Note] Added new Master_info '' to hash table
2020-04-12 12:32:16 140532352559040 [Note] /home/buildbot/buildbot/build/mariadb-10.2.32/sql/mysqld: ready for connections.
Version: '10.2.32-MariaDB-debug-log' socket: '/dev/shm/var/tmp/4/mysqld.1.sock' port: 16020 Source distribution
2020-04-12 12:32:17 140531971667712 [Note] Deleted Master_info file '/dev/shm/var/4/mysqld.1/data/master.info'.
2020-04-12 12:32:17 140531971667712 [Note] Deleted Master_info file '/dev/shm/var/4/mysqld.1/data/relay-log.info'.
2020-04-12 12:32:17 140531970725632 [Note] Start binlog_dump to slave_server(2), pos(master-bin.000001, 4)
sql_set_variables: mutex: LOCK_global_system_variables (0x40416e0) unlocking
mysql_execute_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_parse.cc:5981
close_thread_tables: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_base.cc:725
debug_sync: debug_sync_point: hit: 'before_close_thread_tables'
mysql_parse: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_parse.cc:7756
lex_end: enter: lex: 0x62a0000f3d40
Query_arena::free_items: info: free item: 0x62b00005b388
dispatch_command: info: query ready
dispatch_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_parse.cc:2382
net_send_ok: info: affected_rows: 0 id: 0 status: 2 warning_count: 0
net_send_ok: packet_header: Memory: 0x7fd026283a20 Bytes: (4)
07 00 00 01
vio_is_blocking: exit: 0
vio_write: enter: sd: 22 buf: 0x62900017c208 size: 11
vio_write: exit: 11
net_send_ok: info: OK sent, so no more error sending allowed
killed_errno: enter: killed: 0 killed_errno: 0
dispatch_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_parse.cc:2406
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) locking
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) locked
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) unlocking
my_malloc: my: size: 32 my_flags: 16
my_malloc: info: global thd memory_used: 120592 size: 40
my_malloc: exit: ptr: 0x604000032358
my_malloc: my: size: 40 my_flags: 16
my_malloc: info: global thd memory_used: 120632 size: 48
my_malloc: exit: ptr: 0x604000032398
free_root: enter: root: 0x62a0000f5378 flags: 1
debug_sync: debug_sync_point: hit: 'dispatch_command_end'
my_net_set_read_timeout: enter: timeout: 28800
debug_sync: debug_sync_point: hit: 'before_do_command_net_read'
vio_is_blocking: exit: 0
vio_read: enter: sd: 22 buf: 0x62900017c208 size: 4
vio_read: read_data: Memory: 0x62900017c208 Bytes: (4)
1B 00 00 00
vio_read: exit: 4
do_command: packet_header: Memory: 0x62900017c208 Bytes: (4)
1B 00 00 00
do_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/mysqld.cc:1231
vio_read: enter: sd: 22 buf: 0x62900017c208 size: 27
vio_read: read_data: Memory: 0x62900017c208 Bytes: (27)
03 52 45 50 4C 41 43 45 20 49 4E 54 4F 20 74 31 20 56 41 4C 55 45 53 20 28 34
29
vio_read: exit: 27
fetch_command: info: Command on TCP/IP = 3 (Query)
my_net_set_read_timeout: enter: timeout: 30
dispatch_command: info: command: 3 Query
debug_sync: debug_sync_point: hit: 'dispatch_command_before_set_time'
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b228
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) locking
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) locked
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) unlocking
dispatch_command: mutex: LOCK_log (0x61e000000088) locking
dispatch_command: mutex: LOCK_log (0x61e000000088) locked
my_b_flush_io_cache: enter: cache: 0x61e000000418
my_write: my: fd: 18 Buffer: 0x625000046108 Count: 41 MyFlags: 532
dispatch_command: mutex: LOCK_log (0x61e000000088) unlocking
dispatch_command: query: REPLACE INTO t1 VALUES (4)
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b2b0
lex_start: info: Lex 0x62a0000f3d40
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b2d8
THD::reset_for_next_command: info: Lex and stmt_lex: 0x62a0000f3d40
reset_current_stmt_binlog_format_row: debug: temporary_tables: no, in_sub_stmt: no, system_thread: NON_SYSTEM_THREAD
THD::reset_for_next_command: debug: is_current_stmt_binlog_format_row(): 0
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b2f0
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b300
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b330
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b340
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b960
set_lock_for_tables: enter: lock_type: 9 for_update: 1
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b970
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b990
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b9a0
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005ba38
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005ba50
free_root: enter: root: 0x62a0000f55e0 flags: 0
debug_sync: debug_sync_point: hit: 'before_execute_sql_command'
mysql_execute_command: debug: Just before generate_incident()
Incident_log_event::Incident_log_event: enter: m_incident: 1
MYSQL_BIN_LOG::write(Log_event *): info: direct is set
MYSQL_BIN_LOG::write(Log_event *): mutex: LOCK_log (0x4077c68) locking
MYSQL_BIN_LOG::write(Log_event *): mutex: LOCK_log (0x4077c68) locked
write_gtid_event: enter: standalone: 1
write_gtid_event: mutex: LOCK_binlog_state (0x4079a68) locking
my_hash_first_from_hash_value: exit: found key at 19
write_gtid_event: mutex: LOCK_binlog_state (0x4079a68) locked
my_hash_first_from_hash_value: exit: found key at 0
write_gtid_event: mutex: LOCK_binlog_state (0x4079a68) unlocking
Log_event::write_header: enter: filepos: 724 length: 19 type: 162
MYSQL_BIN_LOG::write(Log_event *): info: event type: 26
Log_event::write_header: enter: filepos: 762 length: 3 type: 26
Incident_log_event::write_data_header: enter: m_incident: 1
my_b_flush_io_cache: enter: cache: 0x4077ff8
my_write: my: fd: 73 Buffer: 0x625000129908 Count: 60 MyFlags: 564
MYSQL_BIN_LOG::write(Log_event *): mutex: LOCK_binlog_end_pos (0x4078248) locking
my_hash_first_from_hash_value: exit: found key at 5
MYSQL_BIN_LOG::write(Log_event *): mutex: LOCK_binlog_end_pos (0x4078248) locked
MYSQL_BIN_LOG::write(Log_event *): mutex: LOCK_binlog_end_pos (0x4078248) unlocking
MYSQL_BIN_LOG::write(Log_event *): mutex: LOCK_after_binlog_sync (0x4079840) locking
my_hash_first_from_hash_value: exit: found key at 3
MYSQL_BIN_LOG::write(Log_event *): mutex: LOCK_after_binlog_sync (0x4079840) locked
MYSQL_BIN_LOG::write(Log_event *): mutex: LOCK_log (0x4077c68) unlocking
MYSQL_BIN_LOG::write(Log_event *): mutex: LOCK_commit_ordered (0x4079920) locking
my_hash_first_from_hash_value: exit: found key at 0
MYSQL_BIN_LOG::write(Log_event *): mutex: LOCK_commit_ordered (0x4079920) locked
MYSQL_BIN_LOG::write(Log_event *): mutex: LOCK_after_binlog_sync (0x4079840) unlocking
MYSQL_BIN_LOG::write(Log_event *): mutex: LOCK_commit_ordered (0x4079920) unlocking
MYSQL_BIN_LOG::rotate_and_purge: mutex: LOCK_log (0x4077c68) locking
MYSQL_BIN_LOG::rotate_and_purge: mutex: LOCK_log (0x4077c68) locked
TC_LOG_BINLOG::mark_xids_active: info: binlog_id=3 xid_count=1
TC_LOG_BINLOG::mark_xids_active: mutex: LOCK_xid_list (0x40782f8) locking
my_hash_first_from_hash_value: exit: found key at 14
TC_LOG_BINLOG::mark_xids_active: mutex: LOCK_xid_list (0x40782f8) locked
TC_LOG_BINLOG::mark_xids_active: mutex: LOCK_xid_list (0x40782f8) unlocking
MYSQL_BIN_LOG::new_file_impl: mutex: LOCK_index (0x4078198) locking
MYSQL_BIN_LOG::new_file_impl: mutex: LOCK_index (0x4078198) locked
fn_format: enter: name: master-bin dir: . extension: flag: 4
dirname_part: enter: 'master-bin'
dirname_part: enter: './'
cleanup_dirname: enter: from: './'
cleanup_dirname: exit: to: './'
fn_ext: mfunkt: name: 'master-bin'
dirname_part: enter: './master-bin'
my_dir: my: path: './' MyFlags: 0
mysql_binlog_send: mutex: LOCK_binlog_end_pos (0x4078248) unlocking
mysql_binlog_send: mutex: var->mutex (0x61300013ff40) locking
mysql_binlog_send: mutex: var->mutex (0x61300013ff40) locked
mysql_binlog_send: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_repl.cc:2470
mysql_binlog_send: mutex: var->mutex (0x61300013ff40) unlocking
my_free: my: ptr: 0x607000037148
my_free: info: global thd memory_used: 25400 size: -80
my_read: my: fd: 20 Buffer: 0x625000115908 Count: 60 MyFlags: 528
my_malloc: my: size: 152 my_flags: 16
my_malloc: info: global thd memory_used: 25320 size: 160
my_malloc: exit: ptr: 0x60e000010f88
my_malloc: my: size: 40 my_flags: 16
my_malloc: info: global thd memory_used: 25480 size: 48
my_malloc: exit: ptr: 0x604000030658
my_free: my: ptr: 0x60e000010f88
my_free: info: global thd memory_used: 25528 size: -160
mysql_binlog_send: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_repl.cc:1924
mysql_binlog_send: packet_header: Memory: 0x7fd0263160e0 Bytes: (4)
27 00 00 12
mysql_binlog_send: info: log event code -94
my_free: my: ptr: 0x604000030658
my_free: info: global thd memory_used: 25368 size: -48
my_malloc: my: size: 152 my_flags: 16
my_malloc: info: global thd memory_used: 25320 size: 160
my_malloc: exit: ptr: 0x60e000011068
my_malloc: my: size: 24 my_flags: 16
my_malloc: info: global thd memory_used: 25480 size: 32
my_malloc: exit: ptr: 0x60300003da58
my_free: my: ptr: 0x60e000011068
my_free: info: global thd memory_used: 25512 size: -160
mysql_binlog_send: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_repl.cc:1924
mysql_binlog_send: packet_header: Memory: 0x7fd0263160e0 Bytes: (4)
17 00 00 13
mysql_binlog_send: info: log event code 26
mysql_binlog_send: mutex: LOCK_binlog_end_pos (0x4078248) locking
mysql_binlog_send: mutex: LOCK_binlog_end_pos (0x4078248) locked
mysql_binlog_send: mutex: LOCK_binlog_end_pos (0x4078248) unlocking
vio_is_blocking: exit: 0
vio_write: enter: sd: 19 buf: 0x62900015e208 size: 70
vio_write: exit: 70
mysql_binlog_send: mutex: LOCK_binlog_end_pos (0x4078248) locking
mysql_binlog_send: mutex: LOCK_binlog_end_pos (0x4078248) locked
mysql_binlog_send: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_repl.cc:2398
my_malloc: my: size: 104 my_flags: 32
my_malloc: info: global thd memory_used: 120680 size: 112
my_malloc: exit: ptr: 0x60b0000ab138
my_malloc: my: size: 8192 my_flags: 0
my_malloc: info: global thd memory_used: 120792 size: 8200
my_malloc: exit: ptr: 0x62500012c108
init_alloc_root: enter: root: 0x60b0000ab168 prealloc: 32768
my_malloc: my: size: 32792 my_flags: 0
my_malloc: info: global thd memory_used: 128992 size: 32800
my_malloc: exit: ptr: 0x62d000212408
alloc_root: enter: root: 0x60b0000ab168
alloc_root: exit: ptr: 0x62d000212428
alloc_root: enter: root: 0x60b0000ab168
alloc_root: exit: ptr: 0x62d000212448
alloc_root: enter: root: 0x60b0000ab168
alloc_root: exit: ptr: 0x62d000212468
alloc_root: enter: root: 0x60b0000ab168
alloc_root: exit: ptr: 0x62d000212488
alloc_root: enter: root: 0x60b0000ab168
alloc_root: exit: ptr: 0x62d0002124a8
alloc_root: enter: root: 0x60b0000ab168
alloc_root: exit: ptr: 0x62d0002124c8
alloc_root: enter: root: 0x60b0000ab168
alloc_root: exit: ptr: 0x62d0002124e8
alloc_root: enter: root: 0x60b0000ab168
alloc_root: exit: ptr: 0x62d0002124f8
alloc_root: enter: root: 0x60b0000ab168
alloc_root: exit: ptr: 0x62d000212508
alloc_root: enter: root: 0x60b0000ab168
alloc_root: exit: ptr: 0x62d000212518
alloc_root: enter: root: 0x60b0000ab168
alloc_root: exit: ptr: 0x62d000212530
alloc_root: enter: root: 0x60b0000ab168
alloc_root: exit: ptr: 0x62d000212548
alloc_root: enter: root: 0x60b0000ab168
alloc_root: exit: ptr: 0x62d000212568
alloc_root: enter: root: 0x60b0000ab168
alloc_root: exit: ptr: 0x62d000212578
alloc_root: enter: root: 0x60b0000ab168
alloc_root: exit: ptr: 0x62d000212588
my_free: my: ptr: 0x62500012c108
my_free: info: global thd memory_used: 161792 size: -8200
free_root: enter: root: 0x60b0000ab168 flags: 0
my_free: my: ptr: 0x62d000212408
my_free: info: global thd memory_used: 153592 size: -32800
my_free: my: ptr: 0x60b0000ab138
my_free: info: global thd memory_used: 120792 size: -112
Rotate_log_event::Rotate_log_event(...,flags): enter: new_log_ident: master-bin.000003 pos: 4 flags: 0
Log_event::write_header: enter: filepos: 784 length: 25 type: 4
MYSQL_BIN_LOG::close: enter: exiting: 11
MYSQL_LOG::close: enter: exiting: 11
end_io_cache: enter: cache: 0x4077ff8
my_b_flush_io_cache: enter: cache: 0x4077ff8
my_write: my: fd: 73 Buffer: 0x625000129908 Count: 44 MyFlags: 564
my_free: my: ptr: 0x625000129908
my_free: info: global thd memory_used: 120680 size: -8200
my_sync: my: fd: 73 my_flags: 16
my_free: my: ptr: 0x0
end_io_cache: enter: cache: 0x4078420
my_b_flush_io_cache: enter: cache: 0x4078420
my_free: my: ptr: 0x625000122108
my_free: info: global thd memory_used: 112480 size: -8200
my_close: my: fd: 3 MyFlags: 0
my_close: mutex: THR_LOCK_open (0x49424c8) locking
my_hash_first_from_hash_value: exit: found key at 2
my_close: mutex: THR_LOCK_open (0x49424c8) locked
my_free: my: ptr: 0x60300003f0d8
my_free: info: global thd memory_used: 104280 size: -32
my_close: mutex: THR_LOCK_open (0x49424c8) unlocking
my_free: my: ptr: 0x0
fn_format: enter: name: ./master-bin.index dir: . extension: .index flag: 4
dirname_part: enter: './master-bin.index'
dirname_part: enter: './'
cleanup_dirname: enter: from: './'
cleanup_dirname: exit: to: './'
my_open: my: Name: './master-bin.index' Flags: 524354 MyFlags: 16
my_register_filename: mutex: THR_LOCK_open (0x49424c8) locking
my_hash_first_from_hash_value: exit: found key at 2
my_register_filename: mutex: THR_LOCK_open (0x49424c8) locked
my_malloc: my: size: 19 my_flags: 16
my_malloc: info: global thd memory_used: 104248 size: 32
my_malloc: exit: ptr: 0x60300003f3a8
my_register_filename: mutex: THR_LOCK_open (0x49424c8) unlocking
my_register_filename: exit: fd: 3
my_realpath: info: executing realpath
my_sync: my: fd: 3 my_flags: 16
my_seek: my: fd: 3 Pos: 0 Whence: 2 MyFlags: 0
my_seek: exit: pos: 40
init_io_cache: enter: cache:0x4078420 type: 2 pos: 40
my_tell: my: fd: 3 MyFlags: 0
my_seek: my: fd: 3 Pos: 0 Whence: 1 MyFlags: 0
my_seek: exit: pos: 40
my_tell: exit: pos: 40
my_malloc: my: size: 8192 my_flags: 16
my_malloc: info: global thd memory_used: 104280 size: 8200
my_malloc: exit: ptr: 0x62500012e908
init_io_cache: info: init_io_cache: cachesize = 8192
fn_format: enter: name: ./master-bin.index dir: . extension: .~rec~ flag: 70
dirname_part: enter: './master-bin.index'
dirname_part: enter: './'
cleanup_dirname: enter: from: './'
cleanup_dirname: exit: to: './'
my_open: my: Name: './master-bin.~rec~' Flags: 66 MyFlags: 16
my_register_filename: mutex: THR_LOCK_open (0x49424c8) locking
my_hash_first_from_hash_value: exit: found key at 2
my_register_filename: mutex: THR_LOCK_open (0x49424c8) locked
my_malloc: my: size: 19 my_flags: 16
my_malloc: info: global thd memory_used: 112480 size: 32
my_malloc: exit: ptr: 0x60300003f3d8
my_register_filename: mutex: THR_LOCK_open (0x49424c8) unlocking
my_register_filename: exit: fd: 74
init_io_cache: enter: cache:0x4078790 type: 1 pos: 0
my_tell: my: fd: 74 MyFlags: 0
my_seek: my: fd: 74 Pos: 0 Whence: 1 MyFlags: 0
my_tell: exit: pos: 0
my_seek: my: fd: 74 Pos: 0 Whence: 2 MyFlags: 0
my_malloc: my: size: 8192 my_flags: 20
my_malloc: info: global thd memory_used: 112512 size: 8200
my_malloc: exit: ptr: 0x625000131108
init_io_cache: info: init_io_cache: cachesize = 8192
safe_mutex_init: enter: mutex: 0x7fd02627cd80 name: &lock
safe_mutex_init: enter: mutex: 0x7fd02627d0d0 name: &lock
reinit_io_cache: enter: cache:0x4078790 type: 1 seek_offset: 0 clear_cache: 0
safe_mutex_destroy: enter: mutex: 0x7fd02627d0d0 name: lock
safe_mutex_destroy: enter: mutex: 0x7fd02627cd80 name: lock
end_io_cache: enter: cache: 0x4078790
my_b_flush_io_cache: enter: cache: 0x4078790
my_free: my: ptr: 0x625000131108
my_free: info: global thd memory_used: 120712 size: -8200
my_close: my: fd: 74 MyFlags: 0
my_close: mutex: THR_LOCK_open (0x49424c8) locking
my_hash_first_from_hash_value: exit: found key at 2
my_close: mutex: THR_LOCK_open (0x49424c8) locked
my_free: my: ptr: 0x60300003f3d8
my_free: info: global thd memory_used: 112512 size: -32
my_close: mutex: THR_LOCK_open (0x49424c8) unlocking
my_delete: my: name ./master-bin.~rec~ MyFlags 0
MYSQL_BIN_LOG::open: enter: log_type: 2
MYSQL_LOG::init: info: log_type: 2
my_delete: my: name ./master-bin.~rec~ MyFlags 0
my_open: my: Name: './master-bin.~rec~' Flags: 66 MyFlags: 16
my_register_filename: mutex: THR_LOCK_open (0x49424c8) locking
my_hash_first_from_hash_value: exit: found key at 2
my_register_filename: mutex: THR_LOCK_open (0x49424c8) locked
my_malloc: my: size: 19 my_flags: 16
my_malloc: info: global thd memory_used: 112480 size: 32
my_malloc: exit: ptr: 0x60300003f408
my_register_filename: mutex: THR_LOCK_open (0x49424c8) unlocking
my_register_filename: exit: fd: 74
init_io_cache: enter: cache:0x4078790 type: 2 pos: 0
my_tell: my: fd: 74 MyFlags: 0
my_seek: my: fd: 74 Pos: 0 Whence: 1 MyFlags: 0
my_tell: exit: pos: 0
my_malloc: my: size: 8192 my_flags: 20
my_malloc: info: global thd memory_used: 112512 size: 8200
my_malloc: exit: ptr: 0x625000133908
init_io_cache: info: init_io_cache: cachesize = 8192
my_b_flush_io_cache: enter: cache: 0x4078790
my_write: my: fd: 74 Buffer: 0x625000133908 Count: 20 MyFlags: 564
my_sync: my: fd: 74 my_flags: 65552
MYSQL_LOG::open: enter: log_type: 0
my_malloc: my: size: 11 my_flags: 16
my_malloc: info: global thd memory_used: 120712 size: 24
my_malloc: exit: ptr: 0x60300003f438
my_stat: my: path: './master-bin.000003' stat_area: 0x7fd02627b970 MyFlags: 0
my_stat: error: Got errno: 2 from stat
my_open: my: Name: './master-bin.000003' Flags: 524353 MyFlags: 16
my_register_filename: mutex: THR_LOCK_open (0x49424c8) locking
my_hash_first_from_hash_value: exit: found key at 2
my_register_filename: mutex: THR_LOCK_open (0x49424c8) locked
my_malloc: my: size: 20 my_flags: 16
my_malloc: info: global thd memory_used: 120736 size: 32
my_malloc: exit: ptr: 0x60300003f468
my_register_filename: mutex: THR_LOCK_open (0x49424c8) unlocking
my_register_filename: exit: fd: 75
my_realpath: info: executing realpath
my_tell: my: fd: 75 MyFlags: 16
my_seek: my: fd: 75 Pos: 0 Whence: 1 MyFlags: 0
my_tell: exit: pos: 0
init_io_cache: enter: cache:0x4077ff8 type: 2 pos: 0
my_tell: my: fd: 75 MyFlags: 0
my_seek: my: fd: 75 Pos: 0 Whence: 1 MyFlags: 0
my_tell: exit: pos: 0
my_malloc: my: size: 8192 my_flags: 20
my_malloc: info: global thd memory_used: 120768 size: 8200
my_malloc: exit: ptr: 0x625000136108
init_io_cache: info: init_io_cache: cachesize = 8192
MYSQL_BIN_LOG::init: info: max_size: 1073741824
my_malloc: my: size: 172 my_flags: 0
my_malloc: info: global thd memory_used: 128968 size: 184
my_malloc: exit: ptr: 0x610000020148
MYSQL_BIN_LOG::open: info: Format_description_log_event::server_version_split: '10.2.32-MariaDB-debug-log' 10 2 32
Log_event::write_header: enter: filepos: 4 length: 229 type: 15
Log_event_writer::write_header: info: crc: 3555451164
Log_event_writer::write_data: info: crc: 1775616835
Log_event_writer::write_data: info: crc: 1680981876
Log_event_writer::write_data: info: crc: 2232314647
Log_event::write_header: enter: filepos: 256 length: 17 type: 164
MYSQL_BIN_LOG::open: mutex: LOCK_binlog_state (0x4079a68) locking
my_hash_first_from_hash_value: exit: found key at 19
MYSQL_BIN_LOG::open: mutex: LOCK_binlog_state (0x4079a68) locked
MYSQL_BIN_LOG::open: mutex: LOCK_binlog_state (0x4079a68) unlocking
my_malloc: my: size: 16 my_flags: 16
my_malloc: info: global thd memory_used: 129152 size: 24
my_malloc: exit: ptr: 0x60300003f498
MYSQL_BIN_LOG::open: mutex: LOCK_binlog_state (0x4079a68) locking
my_hash_first_from_hash_value: exit: found key at 19
MYSQL_BIN_LOG::open: mutex: LOCK_binlog_state (0x4079a68) locked
MYSQL_BIN_LOG::open: mutex: LOCK_binlog_state (0x4079a68) unlocking
Log_event::write_header: enter: filepos: 292 length: 20 type: 163
my_malloc: my: size: 72 my_flags: 4120
my_malloc: info: global thd memory_used: 129176 size: 80
my_malloc: exit: ptr: 0x60700003a9b8
my_malloc: my: size: 17 my_flags: 32
my_malloc: info: global thd memory_used: 129256 size: 32
my_malloc: exit: ptr: 0x60300003f4c8
MYSQL_BIN_LOG::open: mutex: LOCK_xid_list (0x40782f8) locking
my_hash_first_from_hash_value: exit: found key at 14
MYSQL_BIN_LOG::open: mutex: LOCK_xid_list (0x40782f8) locked
MYSQL_BIN_LOG::open: mutex: LOCK_xid_list (0x40782f8) unlocking
my_malloc: my: size: 18 my_flags: 16
my_malloc: info: global thd memory_used: 129288 size: 32
my_malloc: exit: ptr: 0x60300003f4f8
Log_event::write_header: enter: filepos: 331 length: 21 type: 161
my_free: my: ptr: 0x60300003f4f8
my_free: info: global thd memory_used: 129320 size: -32
my_free: my: ptr: 0x60300003f498
my_free: info: global thd memory_used: 129288 size: -24
my_free: my: ptr: 0x0
my_free: my: ptr: 0x610000020148
my_free: info: global thd memory_used: 129264 size: -184
my_b_flush_io_cache: enter: cache: 0x4077ff8
my_write: my: fd: 75 Buffer: 0x625000136108 Count: 371 MyFlags: 564
my_sync: my: fd: 75 my_flags: 65552
MYSQL_BIN_LOG::open: mutex: LOCK_binlog_end_pos (0x4078248) locking
my_hash_first_from_hash_value: exit: found key at 5
MYSQL_BIN_LOG::open: mutex: LOCK_binlog_end_pos (0x4078248) locked
MYSQL_BIN_LOG::open: mutex: LOCK_binlog_end_pos (0x4078248) unlocking
MYSQL_BIN_LOG::open: mutex: LOCK_commit_ordered (0x4079920) locking
mysql_binlog_send: mutex: LOCK_binlog_end_pos (0x4078248) unlocking
mysql_binlog_send: mutex: var->mutex (0x61300013ff40) locking
mysql_binlog_send: mutex: var->mutex (0x61300013ff40) locked
my_hash_first_from_hash_value: exit: found key at 8
MYSQL_BIN_LOG::open: mutex: LOCK_commit_ordered (0x4079920) locked
MYSQL_BIN_LOG::open: mutex: LOCK_commit_ordered (0x4079920) unlocking
debug_sync: debug_sync_point: hit: 'binlog_open_before_update_index'
reinit_io_cache: enter: cache:0x4078420 type: 2 seek_offset: 40 clear_cache: 0
my_b_flush_io_cache: enter: cache: 0x4078420
my_write: my: fd: 3 Buffer: 0x62500012e908 Count: 20 MyFlags: 564
mysql_binlog_send: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_repl.cc:2470
my_sync: my: fd: 3 my_flags: 65552
MYSQL_BIN_LOG::open: mutex: LOCK_xid_list (0x40782f8) locking
my_hash_first_from_hash_value: exit: found key at 14
MYSQL_BIN_LOG::open: mutex: LOCK_xid_list (0x40782f8) locked
MYSQL_BIN_LOG::open: mutex: LOCK_xid_list (0x40782f8) unlocking
end_io_cache: enter: cache: 0x4078790
my_b_flush_io_cache: enter: cache: 0x4078790
my_free: my: ptr: 0x625000133908
my_free: info: global thd memory_used: 129080 size: -8200
my_close: my: fd: 74 MyFlags: 0
my_close: mutex: THR_LOCK_open (0x49424c8) locking
my_hash_first_from_hash_value: exit: found key at 2
my_close: mutex: THR_LOCK_open (0x49424c8) locked
my_free: my: ptr: 0x60300003f408
my_free: info: global thd memory_used: 120880 size: -32
my_close: mutex: THR_LOCK_open (0x49424c8) unlocking
my_delete: my: name ./master-bin.~rec~ MyFlags 0
mysql_binlog_send: mutex: var->mutex (0x61300013ff40) unlocking
my_free: my: ptr: 0x60300003f168
my_free: info: global thd memory_used: 120848 size: -24
my_pwrite: my: fd: 73 Seek: 21 Buffer: 0x7fd02627d6c0 Count: 1 MyFlags: 0
my_close: my: fd: 73 MyFlags: 16
my_close: mutex: THR_LOCK_open (0x49424c8) locking
my_hash_first_from_hash_value: exit: found key at 2
my_close: mutex: THR_LOCK_open (0x49424c8) locked
my_free: my: ptr: 0x60300003f198
my_free: info: global thd memory_used: 120824 size: -32
my_close: mutex: THR_LOCK_open (0x49424c8) unlocking
MYSQL_BIN_LOG::new_file_impl: mutex: LOCK_index (0x4078198) unlocking
MYSQL_BIN_LOG::rotate_and_purge: mutex: LOCK_log (0x4077c68) unlocking
MYSQL_BIN_LOG::rotate_and_purge: mutex: LOCK_xid_list (0x40782f8) locking
MYSQL_BIN_LOG::rotate_and_purge: mutex: LOCK_xid_list (0x40782f8) locked
MYSQL_BIN_LOG::rotate_and_purge: mutex: LOCK_xid_list (0x40782f8) unlocking
plugin_foreach_with_mask: mutex: LOCK_plugin (0x404d260) locking
plugin_foreach_with_mask: mutex: LOCK_plugin (0x404d260) locked
my_malloc: my: size: 8 my_flags: 16
my_malloc: info: global thd memory_used: 120792 size: 16
my_malloc: exit: ptr: 0x602000011518
intern_plugin_lock: lock: thd: 0x62a0000f0208 plugin: "wsrep" LOCK ref_count: 1
my_malloc: my: size: 8 my_flags: 16
my_malloc: info: global thd memory_used: 120808 size: 16
my_malloc: exit: ptr: 0x602000011538
intern_plugin_lock: lock: thd: 0x62a0000f0208 plugin: "binlog" LOCK ref_count: 2
my_malloc: my: size: 8 my_flags: 16
my_malloc: info: global thd memory_used: 120824 size: 16
my_malloc: exit: ptr: 0x602000011558
intern_plugin_lock: lock: thd: 0x62a0000f0208 plugin: "MRG_MyISAM" LOCK ref_count: 1
my_malloc: my: size: 8 my_flags: 16
my_malloc: info: global thd memory_used: 120840 size: 16
my_malloc: exit: ptr: 0x602000011578
intern_plugin_lock: lock: thd: 0x62a0000f0208 plugin: "CSV" LOCK ref_count: 3
my_malloc: my: size: 8 my_flags: 16
my_malloc: info: global thd memory_used: 120856 size: 16
my_malloc: exit: ptr: 0x602000011598
intern_plugin_lock: lock: thd: 0x62a0000f0208 plugin: "MyISAM" LOCK ref_count: 43
my_malloc: my: size: 8 my_flags: 16
my_malloc: info: global thd memory_used: 120872 size: 16
my_malloc: exit: ptr: 0x6020000115b8
intern_plugin_lock: lock: thd: 0x62a0000f0208 plugin: "MEMORY" LOCK ref_count: 1
my_malloc: my: size: 8 my_flags: 16
my_malloc: info: global thd memory_used: 120888 size: 16
my_malloc: exit: ptr: 0x6020000115d8
intern_plugin_lock: lock: thd: 0x62a0000f0208 plugin: "InnoDB" LOCK ref_count: 3
my_malloc: my: size: 8 my_flags: 16
my_malloc: info: global thd memory_used: 120904 size: 16
my_malloc: exit: ptr: 0x6020000115f8
intern_plugin_lock: lock: thd: 0x62a0000f0208 plugin: "Aria" LOCK ref_count: 1
my_malloc: my: size: 8 my_flags: 16
my_malloc: info: global thd memory_used: 120920 size: 16
my_malloc: exit: ptr: 0x602000011618
intern_plugin_lock: lock: thd: 0x62a0000f0208 plugin: "PERFORMANCE_SCHEMA" LOCK ref_count: 1
plugin_foreach_with_mask: mutex: LOCK_plugin (0x404d260) unlocking
TC_LOG_BINLOG::mark_xids_active: info: binlog_id=3 xid_count=1
TC_LOG_BINLOG::mark_xids_active: mutex: LOCK_xid_list (0x40782f8) locking
TC_LOG_BINLOG::mark_xids_active: mutex: LOCK_xid_list (0x40782f8) locked
TC_LOG_BINLOG::mark_xids_active: mutex: LOCK_xid_list (0x40782f8) unlocking
my_malloc: my: size: 32 my_flags: 16
my_malloc: info: global thd memory_used: 120936 size: 40
my_malloc: exit: ptr: 0x6040000323d8
plugin_foreach_with_mask: mutex: pending_checkpoint_mutex (0x407b360) locking
plugin_foreach_with_mask: mutex: pending_checkpoint_mutex (0x407b360) locked
plugin_foreach_with_mask: mutex: pending_checkpoint_mutex (0x407b360) unlocking
plugin_foreach_with_mask: mutex: LOCK_binlog_background_thread (0x4078bf8) locking
plugin_foreach_with_mask: mutex: LOCK_binlog_background_thread (0x4078bf8) locked
my_seek: my: fd: 20 Pos: 0 Whence: 2 MyFlags: 0
plugin_foreach_with_mask: mutex: LOCK_binlog_background_thread (0x4078bf8) unlocking
my_seek: exit: pos: 828
binlog_background_thread: mutex: LOCK_binlog_background_thread (0x4078bf8) unlocking
binlog_background_thread: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/log.cc:9920
debug_sync: debug_sync_point: hit: 'binlog_background_thread_before_mark_xid_done'
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_xid_list (0x40782f8) locking
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_xid_list (0x40782f8) locked
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_xid_list (0x40782f8) unlocking
binlog_background_thread: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/log.cc:9886
binlog_background_thread: mutex: LOCK_binlog_background_thread (0x4078bf8) locking
binlog_background_thread: mutex: LOCK_binlog_background_thread (0x4078bf8) locked
my_free: my: ptr: 0x60300003da58
my_free: info: global thd memory_used: 25352 size: -32
my_free: my: ptr: 0x6040000323d8
my_free: info: global thd memory_used: 120976 size: -40
plugin_unlock_list: mutex: LOCK_plugin (0x404d260) locking
plugin_unlock_list: mutex: LOCK_plugin (0x404d260) locked
my_free: my: ptr: 0x602000011518
my_free: info: global thd memory_used: 120936 size: -16
my_seek: my: fd: 20 Pos: 784 Whence: 0 MyFlags: 0
intern_plugin_unlock: lock: thd: 0x62a0000f0208 plugin: "wsrep" UNLOCK ref_count: 0
my_free: my: ptr: 0x602000011538
my_free: info: global thd memory_used: 120920 size: -16
intern_plugin_unlock: lock: thd: 0x62a0000f0208 plugin: "binlog" UNLOCK ref_count: 1
my_free: my: ptr: 0x602000011558
my_free: info: global thd memory_used: 120904 size: -16
intern_plugin_unlock: lock: thd: 0x62a0000f0208 plugin: "MRG_MyISAM" UNLOCK ref_count: 0
my_free: my: ptr: 0x602000011578
my_free: info: global thd memory_used: 120888 size: -16
intern_plugin_unlock: lock: thd: 0x62a0000f0208 plugin: "CSV" UNLOCK ref_count: 2
my_free: my: ptr: 0x602000011598
my_free: info: global thd memory_used: 120872 size: -16
intern_plugin_unlock: lock: thd: 0x62a0000f0208 plugin: "MyISAM" UNLOCK ref_count: 42
my_free: my: ptr: 0x6020000115b8
my_free: info: global thd memory_used: 120856 size: -16
intern_plugin_unlock: lock: thd: 0x62a0000f0208 plugin: "MEMORY" UNLOCK ref_count: 0
my_free: my: ptr: 0x6020000115d8
my_free: info: global thd memory_used: 120840 size: -16
intern_plugin_unlock: lock: thd: 0x62a0000f0208 plugin: "InnoDB" UNLOCK ref_count: 2
my_free: my: ptr: 0x6020000115f8
my_free: info: global thd memory_used: 120824 size: -16
intern_plugin_unlock: lock: thd: 0x62a0000f0208 plugin: "Aria" UNLOCK ref_count: 0
my_free: my: ptr: 0x602000011618
my_free: info: global thd memory_used: 120808 size: -16
intern_plugin_unlock: lock: thd: 0x62a0000f0208 plugin: "PERFORMANCE_SCHEMA" UNLOCK ref_count: 0
plugin_unlock_list: mutex: LOCK_plugin (0x404d260) unlocking
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_xid_list (0x40782f8) locking
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_xid_list (0x40782f8) locked
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_xid_list (0x40782f8) unlocking
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_log (0x4077c68) locking
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_log (0x4077c68) locked
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_xid_list (0x40782f8) locking
my_hash_first_from_hash_value: exit: found key at 14
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_xid_list (0x40782f8) locked
my_free: my: ptr: 0x60300003f1c8
my_free: info: global thd memory_used: 120792 size: -32
my_read: my: fd: 20 Buffer: 0x625000115908 Count: 44 MyFlags: 528
my_free: my: ptr: 0x60700003a948
my_free: info: global thd memory_used: 120760 size: -80
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_xid_list (0x40782f8) unlocking
my_malloc: my: size: 18 my_flags: 16
my_malloc: info: global thd memory_used: 120680 size: 32
my_malloc: exit: ptr: 0x60300003f528
Log_event::write_header: enter: filepos: 371 length: 21 type: 161
my_b_flush_io_cache: enter: cache: 0x4077ff8
my_write: my: fd: 75 Buffer: 0x625000136108 Count: 40 MyFlags: 564
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_binlog_end_pos (0x4078248) locking
my_hash_first_from_hash_value: exit: found key at 5
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_binlog_end_pos (0x4078248) locked
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_binlog_end_pos (0x4078248) unlocking
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_commit_ordered (0x4079920) locking
my_hash_first_from_hash_value: exit: found key at 8
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_commit_ordered (0x4079920) locked
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_commit_ordered (0x4079920) unlocking
my_free: my: ptr: 0x60300003f528
my_free: info: global thd memory_used: 120712 size: -32
my_malloc: my: size: 152 my_flags: 16
TC_LOG_BINLOG::mark_xid_done: mutex: LOCK_log (0x4077c68) unlocking
mysql_execute_command: debug: Just after generate_incident()
THD::open_temporary_table: enter: table: 'test'.'t1'
THD::open_temporary_table: info: skip_temporary is set or no temporary tables
check_access: enter: db: test want_access: 10 master_access: 536870911
check_access: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_parse.cc:6434
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005ba68
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005bae0
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005bb68
open_and_lock_tables: enter: derived handling: 1
open_tables: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_base.cc:3965
debug_sync: debug_sync_point: hit: 'open_and_process_table'
open_and_process_table: tcache: opening table: 'test'.'t1' item: 0x62b00005b340
MDL_context::acquire_lock: enter: lock_type: 0
my_malloc: info: global thd memory_used: 25320 size: 160
MDL_context::acquire_lock: info: Got lock without waiting
MDL_context::acquire_lock: enter: lock_type: 4
MDL_context::acquire_lock: info: Got lock without waiting
debug_sync: debug_sync_point: hit: 'after_open_table_mdl_shared'
tdc_acquire_share: mutex: LOCK_table_cache (0x616000001288) locking
tdc_acquire_share: mutex: LOCK_table_cache (0x616000001288) locked
mi_extra: enter: function: 45
tdc_acquire_share: mutex: LOCK_table_cache (0x616000001288) unlocking
open_table: mutex: LOCK_thd_data (0x62a0000f1b50) locking
open_table: mutex: LOCK_thd_data (0x62a0000f1b50) locked
open_table: mutex: LOCK_thd_data (0x62a0000f1b50) unlocking
column_bitmaps_signal: info: read_set: 0x61e00003fda8 write_set: 0x61e00003fdc8
mi_extra: enter: function: 45
mi_extra: enter: function: 43
debug_sync: debug_sync_point: hit: 'open_tables_after_open_and_process_table'
open_tables: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_base.cc:4215
open_tables: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_base.cc:4216
open_tables: open_tables: returning: 0
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005bbf0
debug_sync: debug_sync_point: hit: 'before_lock_tables_takes_lock'
lock_tables_check: info: Adding mdl lock 4 to 4
get_lock_data: info: count 1
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005bc00
get_lock_data: info: sql_lock->table_count 1 sql_lock->lock_count 1
mysql_lock_tables(sql_lock): THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/lock.cc:339
lock_external: info: count 1
mi_lock_database: enter: lock_type: 1 old lock 2 r_locks: 0 w_locks: 0 global_changed: 1 open_count: 1 name: './test/t1.MYI'
mi_lock_database: mutex: share->intern_lock (0x61c000062570) locking
mi_lock_database: mutex: share->intern_lock (0x61c000062570) locked
my_lock: my: fd: 72 Op: 1 start: 0 Length: 0 MyFlags: 32
list_add: enter: root: 0x0 element: 0x619000111d60
mi_lock_database: mutex: share->intern_lock (0x61c000062570) unlocking
mysql_lock_tables(sql_lock): THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/lock.cc:344
debug_sync: debug_sync_point: hit: 'thr_multi_lock_before_thr_lock'
mysql_lock_tables(sql_lock): mutex: lock->mutex (0x61c000062428) locking
mysql_lock_tables(sql_lock): mutex: lock->mutex (0x61c000062428) locked
mi_get_status: info: name: ./test/t1.MYI key_file: 1024 data_file: 21 rows: 3 concurrent_insert: 0
mysql_lock_tables(sql_lock): mutex: lock->mutex (0x61c000062428) unlocking
debug_sync: debug_sync_point: hit: 'thr_multi_lock_after_thr_lock'
mysql_lock_tables(sql_lock): THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/lock.cc:359
debug_sync: debug_sync_point: hit: 'after_lock_tables_takes_lock'
THD::decide_logging_format: info: Query: REPLACE INTO t1 VALUES (4)
THD::decide_logging_format: info: variables.binlog_format: 0
THD::decide_logging_format: info: lex->get_stmt_unsafe_flags(): 0x0
THD::decide_logging_format: debug: prelocked_mode: NON_PRELOCKED
THD::decide_logging_format: info: table: t1; ha_table_flags: 0x20ad14626dd1
THD::decide_logging_format: info: flags_write_all_set: 0xc00000000
THD::decide_logging_format: info: flags_write_some_set: 0x20ad14626dd1
THD::decide_logging_format: info: flags_access_some_set: 0x20ad14626dd1
THD::decide_logging_format: info: multi_write_engine: 0
THD::decide_logging_format: info: multi_access_engine: 0
THD::decide_logging_format: info: decision: logging in STATEMENT format
mysql_handle_derived: enter: phases: 0x1
mysql_insert: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_insert.cc:764
mysql_prepare_insert: enter: table_list: 0x62b00005b340 table: 0x0 view: 0
mysql_handle_derived: enter: phases: 0x1
handle_derived: enter: phases: 0x10
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005bc38
setup_fields: enter: ref_pointer_array: 0x0
setup_fields: info: thd->mark_used_columns: 1
setup_fields: info: thd->mark_used_columns: 1
Field_iterator_table_ref::set_field_iterator: info: field_it for 't1' is Field_iterator_table
setup_fields: enter: ref_pointer_array: 0x0
setup_fields: info: thd->mark_used_columns: 1
setup_fields: info: thd->mark_used_columns: 1
find_dup_table: enter: table alias: t1
find_dup_table: info: real table: test.t1
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005bc50
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005bcf0
mysql_insert: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_insert.cc:861
mi_extra: enter: function: 37
mi_extra: enter: function: 25
mysql_insert: info: iteration 0
debug_sync: debug_sync_point: hit: 'ha_write_row_start'
mi_write: enter: isam: 72 data: 70
my_pwrite: my: fd: 70 Seek: 21 Buffer: 0x6190001117b8 Count: 5 MyFlags: 36
my_pwrite: my: fd: 70 Seek: 26 Buffer: 0x7fd02627d940 Count: 2 MyFlags: 36
my_malloc: exit: ptr: 0x60e000011148
my_malloc: my: size: 46 my_flags: 16
_mi_writeinfo: info: operation: 1 tot_locks: 1
debug_sync: debug_sync_point: hit: 'ha_write_row_end'
mi_extra: enter: function: 26
THD::binlog_query: enter: qtype: ROW query: 'REPLACE INTO t1 VALUES (4)'
THD::binlog_query: info: is_trans: 0 direct: 0
THD::binlog_query: debug: is_current_stmt_binlog_format_row: 0
THD::binlog_query: info: Query_log_event has flags2: 0 sql_mode: 1411383296 cache_tye: 1
binlog_start_trans_and_stmt: enter: cache_mngr: 0x61a000040288 cache_mngr->trx_cache.get_prev_position(): 18446744073709551615
binlog_trans_log_savepos: return: *pos: 0
trans_register_ha: enter: stmt
MYSQL_BIN_LOG::write(Log_event *): info: event type: 2
Log_event::write_header: enter: filepos: 0 length: 70 type: 2
my_malloc: info: global thd memory_used: 25480 size: 56
my_malloc: exit: ptr: 0x6060000c0388
mysql_insert: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_insert.cc:1193
mi_extra: enter: function: 38
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005bd38
debug_sync: debug_sync_point: hit: 'after_mysql_insert'
mysql_execute_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_parse.cc:5981
ha_commit_trans: info: thd: 0x62a0000f0208 option_bits: 2147748608 all: 0
ha_commit_trans: info: all: 0 thd->in_sub_stmt: 0 ha_info: 0x62a0000f2540 is_real_trans: 1
ha_commit_trans: info: is_real_trans: 1 rw_trans: 0 rw_ha_count: 1
debug_sync: debug_sync_point: hit: 'ha_commit_one_phase'
debug_sync: debug_sync_point: hit: 'commit_one_phase_2'
binlog_commit: debug: all: 0, in_transaction: no, all.modified_non_trans_table: yes, stmt.modified_non_trans_table: yes
binlog_commit_flush_stmt_cache: info: Query_log_event has flags2: 0 sql_mode: 1411383296 cache_tye: 3
binlog_flush_cache: enter: end_ev: 0x7fd02627e100
debug_sync: debug_sync_point: hit: 'commit_before_enqueue'
MYSQL_BIN_LOG::queue_for_group_commit: mutex: LOCK_prepare_ordered (0x4079700) locking
MYSQL_BIN_LOG::queue_for_group_commit: mutex: LOCK_prepare_ordered (0x4079700) locked
MYSQL_BIN_LOG::queue_for_group_commit: mutex: LOCK_prepare_ordered (0x4079700) unlocking
debug_sync: debug_sync_point: hit: 'commit_after_release_LOCK_prepare_ordered'
MYSQL_BIN_LOG::queue_for_group_commit: info: Queued for group commit as leader

debug_sync: debug_sync_point: hit: 'commit_before_get_LOCK_log'
MYSQL_BIN_LOG::trx_group_commit_leader: mutex: LOCK_log (0x4077c68) locking
MYSQL_BIN_LOG::trx_group_commit_leader: mutex: LOCK_log (0x4077c68) locked
debug_sync: debug_sync_point: hit: 'commit_after_get_LOCK_log'
MYSQL_BIN_LOG::trx_group_commit_leader: mutex: LOCK_prepare_ordered (0x4079700) locking
my_hash_first_from_hash_value: exit: found key at 10
MYSQL_BIN_LOG::trx_group_commit_leader: mutex: LOCK_prepare_ordered (0x4079700) locked
MYSQL_BIN_LOG::trx_group_commit_leader: mutex: LOCK_prepare_ordered (0x4079700) unlocking
write_gtid_event: enter: standalone: 0
write_gtid_event: mutex: LOCK_binlog_state (0x4079a68) locking
my_hash_first_from_hash_value: exit: found key at 19
write_gtid_event: mutex: LOCK_binlog_state (0x4079a68) locked
my_hash_first_from_hash_value: exit: found key at 0
write_gtid_event: mutex: LOCK_binlog_state (0x4079a68) unlocking
Log_event::write_header: enter: filepos: 411 length: 19 type: 162
my_free: my: ptr: 0x60e000011148
my_free: info: global thd memory_used: 25536 size: -160
reinit_io_cache: enter: cache:0x61a000040288 type: 1 seek_offset: 0 clear_cache: 0
mysql_binlog_send: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_repl.cc:1924
Log_event::write_header: enter: filepos: 538 length: 50 type: 2
mysql_binlog_send: packet_header: Memory: 0x7fd0263160e0 Bytes: (4)
2D 00 00 14
mysql_binlog_send: info: log event code 4
my_b_flush_io_cache: enter: cache: 0x4077ff8
my_write: my: fd: 75 Buffer: 0x625000136108 Count: 196 MyFlags: 564
mysql_binlog_send: mutex: LOCK_binlog_end_pos (0x4078248) locking
mysql_binlog_send: mutex: LOCK_binlog_end_pos (0x4078248) locked
mysql_binlog_send: mutex: LOCK_binlog_end_pos (0x4078248) unlocking
MYSQL_BIN_LOG::trx_group_commit_leader: mutex: LOCK_binlog_end_pos (0x4078248) locking
my_hash_first_from_hash_value: exit: found key at 5
MYSQL_BIN_LOG::trx_group_commit_leader: mutex: LOCK_binlog_end_pos (0x4078248) locked
MYSQL_BIN_LOG::trx_group_commit_leader: mutex: LOCK_binlog_end_pos (0x4078248) unlocking
debug_sync: debug_sync_point: hit: 'commit_before_get_LOCK_after_binlog_sync'
MYSQL_BIN_LOG::trx_group_commit_leader: mutex: LOCK_after_binlog_sync (0x4079840) locking
my_hash_first_from_hash_value: exit: found key at 3
MYSQL_BIN_LOG::trx_group_commit_leader: mutex: LOCK_after_binlog_sync (0x4079840) locked
MYSQL_BIN_LOG::trx_group_commit_leader: mutex: LOCK_log (0x4077c68) unlocking
debug_sync: debug_sync_point: hit: 'commit_after_release_LOCK_log'
debug_sync: debug_sync_point: hit: 'commit_before_get_LOCK_commit_ordered'
MYSQL_BIN_LOG::trx_group_commit_leader: mutex: LOCK_commit_ordered (0x4079920) locking
my_hash_first_from_hash_value: exit: found key at 0
MYSQL_BIN_LOG::trx_group_commit_leader: mutex: LOCK_commit_ordered (0x4079920) locked
MYSQL_BIN_LOG::trx_group_commit_leader: mutex: LOCK_after_binlog_sync (0x4079840) unlocking
debug_sync: debug_sync_point: hit: 'commit_after_release_LOCK_after_binlog_sync'
debug_sync: debug_sync_point: hit: 'commit_loop_entry_commit_ordered'
debug_sync: debug_sync_point: hit: 'commit_after_group_run_commit_ordered'
MYSQL_BIN_LOG::trx_group_commit_leader: mutex: LOCK_commit_ordered (0x4079920) unlocking
debug_sync: debug_sync_point: hit: 'commit_after_group_release_commit_ordered'
binlog_flush_cache: info: truncating to position 0
reinit_io_cache: enter: cache:0x61a000040288 type: 2 seek_offset: 0 clear_cache: 0
binlog_commit: info: truncating to position 0
reinit_io_cache: enter: cache:0x61a000040428 type: 2 seek_offset: 0 clear_cache: 0
free_root: enter: root: 0x62a0000f3628 flags: 1
close_thread_tables: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_base.cc:725
debug_sync: debug_sync_point: hit: 'before_close_thread_tables'
close_thread_tables: tcache: table: 't1' query_id: 0
mi_extra: enter: function: 46
mysql_unlock_tables: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/lock.cc:426
mi_lock_database: enter: lock_type: 2 old lock 1 r_locks: 0 w_locks: 1 global_changed: 1 open_count: 1 name: './test/t1.MYI'
mi_lock_database: mutex: share->intern_lock (0x61c000062570) locking
mi_lock_database: mutex: share->intern_lock (0x61c000062570) locked
free_root: enter: root: 0x619000111d18 flags: 0
mi_lock_database: mutex: lock->mutex (0x61c000062428) locking
my_hash_first_from_hash_value: exit: found key at 0
mi_lock_database: mutex: lock->mutex (0x61c000062428) locked
mi_update_status: info: updating status: key_file: 1024 data_file: 28 rows: 4
mi_update_status: info: invalidator... './test/t1' (status update)
check_integrity: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_cache.cc:691
Query_cache::lock_and_suspend: mutex: structure_guard_mutex (0x4045720) locking
my_malloc: my: size: 56 my_flags: 56
my_malloc: info: global thd memory_used: 120680 size: 64
my_malloc: exit: ptr: 0x6060000c3868
add_to_locked_mutex: info: inserting 0x6060000c3868 into 0x61c000062570 (id: 12 -> 229)
add_to_locked_mutex: info: inserting 0x6060000c3868 into 0x4941fb8 (id: 12 -> 18)
add_to_locked_mutex: info: inserting 0x6060000c3868 into 0x4041fa0 (id: 12 -> 3)
add_to_locked_mutex: info: inserting 0x6060000c3868 into 0x61c000062428 (id: 12 -> 231)
Query_cache::lock_and_suspend: mutex: structure_guard_mutex (0x4045720) locked
Query_cache::lock_and_suspend: mutex: structure_guard_mutex (0x4045720) unlocking
check_integrity: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_cache.cc:691
check_integrity: qcache: physical address check ...
check_integrity: qcache: block 0x7fd03596e9e8, type 0...
check_integrity: qcache: check queries ...
check_integrity: qcache: check tables ...
check_integrity: qcache: check free blocks
check_integrity: qcache: block 0x7fd03596e9e8, type 0...
Query_cache::unlock: mutex: structure_guard_mutex (0x4045720) locking
my_hash_first_from_hash_value: exit: found key at 0
Query_cache::unlock: mutex: structure_guard_mutex (0x4045720) locked
Query_cache::unlock: Query_cache: Sending signal
Query_cache::unlock: mutex: structure_guard_mutex (0x4045720) unlocking
mi_lock_database: mutex: lock->mutex (0x61c000062428) unlocking
flush_key_blocks: enter: keycache: 0x615000001208
flush_key_blocks: mutex: keycache->cache_lock (0x6150000012c0) locking
my_hash_first_from_hash_value: exit: found key at 0
flush_key_blocks: mutex: keycache->cache_lock (0x6150000012c0) locked
flush_key_blocks_int: enter: file: 72 blocks_used: 2 blocks_changed: 0
flush_key_blocks: mutex: keycache->cache_lock (0x6150000012c0) unlocking
mi_lock_database: info: changed: 1 w_locks: 0
my_pwrite: my: fd: 72 Seek: 0 Buffer: 0x7fd02627be80 Count: 124 MyFlags: 2052
my_seek: my: fd: 20 Pos: 0 Whence: 2 MyFlags: 0
my_lock: my: fd: 72 Op: 2 start: 0 Length: 0 MyFlags: 48
mi_lock_database: mutex: share->intern_lock (0x61c000062570) unlocking
mysql_unlock_tables: mutex: lock->mutex (0x61c000062428) locking
mysql_unlock_tables: mutex: lock->mutex (0x61c000062428) locked
mysql_unlock_tables: mutex: lock->mutex (0x61c000062428) unlocking
close_thread_table: tcache: table: 'test'.'t1' 0x61e00003fc88
close_thread_table: info: Adding mdl lock 1 to 4
close_thread_table: mutex: LOCK_thd_data (0x62a0000f1b50) locking
close_thread_table: mutex: LOCK_thd_data (0x62a0000f1b50) locked
close_thread_table: mutex: LOCK_thd_data (0x62a0000f1b50) unlocking
mi_extra: enter: function: 46
close_thread_table: mutex: LOCK_table_cache (0x616000001288) locking
close_thread_table: mutex: LOCK_table_cache (0x616000001288) locked
close_thread_table: mutex: LOCK_table_cache (0x616000001288) unlocking
debug_sync: debug_sync_point: hit: 'execute_command_after_close_tables'
MDL_context::release_locks_stored_before: info: found lock to release ticket=0x6060000c37a0
MDL_context::release_lock: enter: db: '' name: ''
MDL_context::release_locks_stored_before: info: found lock to release ticket=0x6060000c3800
MDL_context::release_lock: enter: db: 'test' name: 't1'
mysql_parse: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_parse.cc:7756
lex_end: enter: lex: 0x62a0000f3d40
Query_arena::free_items: info: free item: 0x62b00005b9a0
dispatch_command: info: query ready
dispatch_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_parse.cc:2382
net_send_ok: info: affected_rows: 1 id: 0 status: 2 warning_count: 0
net_send_ok: packet_header: Memory: 0x7fd026283a20 Bytes: (4)
07 00 00 01
vio_is_blocking: exit: 0
vio_write: enter: sd: 22 buf: 0x62900017c208 size: 11
my_seek: exit: pos: 828
mysql_binlog_send: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_repl.cc:2852
mysql_binlog_send: mutex: LOCK_index (0x4078198) locking
mysql_binlog_send: mutex: LOCK_index (0x4078198) locked
reinit_io_cache: enter: cache:0x4078420 type: 1 seek_offset: 40 clear_cache: 0
my_b_flush_io_cache: enter: cache: 0x4078420
vio_write: exit: 11
net_send_ok: info: OK sent, so no more error sending allowed
killed_errno: enter: killed: 0 killed_errno: 0
delete_explain_query: mutex: LOCK_thd_data (0x62a0000f1b50) locking
delete_explain_query: mutex: LOCK_thd_data (0x62a0000f1b50) locked
delete_explain_query: mutex: LOCK_thd_data (0x62a0000f1b50) unlocking
dispatch_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_parse.cc:2406
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) locking
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) locked
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) unlocking
my_seek: my: fd: 3 Pos: 40 Whence: 0 MyFlags: 0
my_malloc: my: size: 40 my_flags: 16
my_malloc: info: global thd memory_used: 120744 size: 48
my_malloc: exit: ptr: 0x604000032418
free_root: enter: root: 0x62a0000f5378 flags: 1
my_read: my: fd: 3 Buffer: 0x62500012e908 Count: 20 MyFlags: 560
debug_sync: debug_sync_point: hit: 'dispatch_command_end'
my_net_set_read_timeout: enter: timeout: 28800
debug_sync: debug_sync_point: hit: 'before_do_command_net_read'
vio_is_blocking: exit: 0
vio_read: enter: sd: 22 buf: 0x62900017c208 size: 4
vio_read: read_data: Memory: 0x62900017c208 Bytes: (4)
13 00 00 00
vio_read: exit: 4
do_command: packet_header: Memory: 0x62900017c208 Bytes: (4)
13 00 00 00
do_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/mysqld.cc:1231
vio_read: enter: sd: 22 buf: 0x62900017c208 size: 19
dirname_part: enter: 'master-bin'
dirname_part: enter: './master-bin.000003
'
vio_read: read_data: Memory: 0x62900017c208 Bytes: (19)
03 73 68 6F 77 20 6D 61 73 74 65 72 20 73 74 61 74 75 73
vio_read: exit: 19
fetch_command: info: Command on TCP/IP = 3 (Query)
my_net_set_read_timeout: enter: timeout: 30
dispatch_command: info: command: 3 Query
debug_sync: debug_sync_point: hit: 'dispatch_command_before_set_time'
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b228
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) locking
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) locked
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) unlocking
mysql_binlog_send: mutex: LOCK_index (0x4078198) unlocking
end_io_cache: enter: cache: 0x7fd026319080
my_b_flush_io_cache: enter: cache: 0x7fd026319080
my_free: my: ptr: 0x625000115908
my_free: info: global thd memory_used: 25376 size: -8200
dispatch_command: mutex: LOCK_log (0x61e000000088) locking
dispatch_command: mutex: LOCK_log (0x61e000000088) locked
my_b_flush_io_cache: enter: cache: 0x61e000000418
my_write: my: fd: 18 Buffer: 0x625000046108 Count: 33 MyFlags: 532
dispatch_command: mutex: LOCK_log (0x61e000000088) unlocking
dispatch_command: query: show master status
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b2a8
lex_start: info: Lex 0x62a0000f3d40
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b2c8
THD::reset_for_next_command: info: Lex and stmt_lex: 0x62a0000f3d40
reset_current_stmt_binlog_format_row: debug: temporary_tables: no, in_sub_stmt: no, system_thread: NON_SYSTEM_THREAD
THD::reset_for_next_command: debug: is_current_stmt_binlog_format_row(): 0
my_close: my: fd: 20 MyFlags: 16
my_close: mutex: THR_LOCK_open (0x49424c8) locking
my_close: mutex: THR_LOCK_open (0x49424c8) locked
debug_sync: debug_sync_point: hit: 'before_execute_sql_command'
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b2e0
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b370
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b388
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b428
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b440
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b4d0
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b4e8
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b578
Protocol::send_result_set_metadata: packet_header: Memory: 0x7fd02627e000 Bytes: (4)
01 00 00 01
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b590
my_free: my: ptr: 0x60300003d9f8
my_free: info: global thd memory_used: 17176 size: -32
Protocol::write: packet_header: Memory: 0x7fd02627e000 Bytes: (4)
1A 00 00 02
Protocol::write: packet_header: Memory: 0x7fd02627e000 Bytes: (4)
1E 00 00 03
Protocol::write: packet_header: Memory: 0x7fd02627e000 Bytes: (4)
22 00 00 04
Protocol::write: packet_header: Memory: 0x7fd02627e000 Bytes: (4)
26 00 00 05
Protocol::send_result_set_metadata: packet_header: Memory: 0x7fd02627e000 Bytes: (4)
05 00 00 06
safe_mutex_init: enter: mutex: 0x7fd02627eae0 name: &lock
show_binlog_info: mutex: LOCK_log (0x4077c68) locking
show_binlog_info: mutex: LOCK_log (0x4077c68) locked
show_binlog_info: mutex: LOCK_log (0x4077c68) unlocking
show_binlog_info: info: Protocol_text::store field 0 (4): master-bin.000003
show_binlog_info: info: Protocol_text::store field 2 (4):
show_binlog_info: info: Protocol_text::store field 3 (4):
Protocol::write: packet_header: Memory: 0x7fd02627e640 Bytes: (4)
18 00 00 07
safe_mutex_destroy: enter: mutex: 0x7fd02627eae0 name: lock
mysql_execute_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_parse.cc:5981
my_close: mutex: THR_LOCK_open (0x49424c8) unlocking
close_thread_tables: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_base.cc:725
debug_sync: debug_sync_point: hit: 'before_close_thread_tables'
debug_sync: debug_sync_point: hit: 'execute_command_after_close_tables'
mysql_parse: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_parse.cc:7756
lex_end: enter: lex: 0x62a0000f3d40
Query_arena::free_items: info: free item: 0x62b00005b4e8
Query_arena::free_items: info: free item: 0x62b00005b440
Query_arena::free_items: info: free item: 0x62b00005b388
Query_arena::free_items: info: free item: 0x62b00005b2e0
dispatch_command: info: query ready
dispatch_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_parse.cc:2382
net_send_eof: packet_header: Memory: 0x7fd026283d80 Bytes: (4)
05 00 00 08
vio_is_blocking: exit: 0
vio_write: enter: sd: 22 buf: 0x62900017c208 size: 195
my_free: my: ptr: 0x6060000c0388
my_free: info: global thd memory_used: 17144 size: -56
my_malloc: my: size: 152 my_flags: 16
my_malloc: info: global thd memory_used: 17088 size: 160
my_malloc: exit: ptr: 0x60e000011228
fake_rotate_event: packet_header: Memory: 0x7fd0263160e0 Bytes: (4)
2D 00 00 15
my_open: my: Name: './master-bin.000003' Flags: 0 MyFlags: 16
vio_write: exit: 195
net_send_eof: info: EOF sent, so no more error sending allowed
killed_errno: enter: killed: 0 killed_errno: 0
dispatch_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/sql_parse.cc:2406
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) locking
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) locked
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) unlocking
my_register_filename: mutex: THR_LOCK_open (0x49424c8) locking
my_register_filename: mutex: THR_LOCK_open (0x49424c8) locked
free_root: enter: root: 0x62a0000f5378 flags: 1
debug_sync: debug_sync_point: hit: 'dispatch_command_end'
my_net_set_read_timeout: enter: timeout: 28800
debug_sync: debug_sync_point: hit: 'before_do_command_net_read'
vio_is_blocking: exit: 0
vio_read: enter: sd: 22 buf: 0x62900017c208 size: 4
vio_read: read_data: Memory: 0x62900017c208 Bytes: (4)
11 00 00 00
vio_read: exit: 4
do_command: packet_header: Memory: 0x62900017c208 Bytes: (4)
11 00 00 00
do_command: THD::enter_stage: /home/buildbot/buildbot/build/mariadb-10.2.32/sql/mysqld.cc:1231
vio_read: enter: sd: 22 buf: 0x62900017c208 size: 17
my_malloc: my: size: 20 my_flags: 16
my_malloc: info: global thd memory_used: 17248 size: 32
my_malloc: exit: ptr: 0x60300003da88
vio_read: read_data: Memory: 0x62900017c208 Bytes: (17)
03 53 45 4C 45 43 54 20 2A 20 46 52 4F 4D 20 74 31
vio_read: exit: 17
fetch_command: info: Command on TCP/IP = 3 (Query)
my_net_set_read_timeout: enter: timeout: 30
dispatch_command: info: command: 3 Query
debug_sync: debug_sync_point: hit: 'dispatch_command_before_set_time'
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr: 0x62b00005b228
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) locking
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) locked
dispatch_command: mutex: LOCK_thd_data (0x62a0000f1b50) unlocking
my_register_filename: mutex: THR_LOCK_open (0x49424c8) unlocking
my_register_filename: exit: fd: 20
my_realpath: info: executing realpath
dispatch_command: mutex: LOCK_log (0x61e000000088) locking
init_io_cache: enter: cache:0x7fd026319080 type: 1 pos: 0
my_tell: my: fd: 20 MyFlags: 0
my_seek: my: fd: 20 Pos: 0 Whence: 1 MyFlags: 0
dispatch_command: mutex: LOCK_log (0x61e000000088) locked
my_b_flush_io_cache: enter: cache: 0x61e000000418
my_write: my: fd: 18 Buffer: 0x625000046108 Count: 31 MyFlags: 532
dispatch_command: mutex: LOCK_log (0x61e000000088) unlocking
dispatch_command: query: SELECT * FROM t1
alloc_root: enter: root: 0x62a0000f5378
alloc_root: exit: ptr

[MDEV-21569] rpl.rpl_row_corruption failed in buildbot: sql_set_variables: mutex: LOCK_global_system_variables unlocking Created: 2020-01-26 Updated: 2021-10-19 Resolved: 2021-10-19
Status:	Closed
Project:	MariaDB Server
Component/s:	Locking, Tests
Affects Version/s:	10.2
Fix Version/s:	N/A

[MDEV-21569] rpl.rpl_row_corruption failed in buildbot: sql_set_variables: mutex: LOCK_global_system_variables unlocking Created: 2020-01-26 Updated: 2021-10-19 Resolved: 2021-10-19