rpl.rpl_gtid_crash sporadic fail in buildbot with Lost connection

rpl.rpl_gtid_crash 'innodb,mix'          w4 [ fail ]

        Test ended at 2017-08-24 15:21:16

CURRENT_TEST: rpl.rpl_gtid_crash

mysqltest: At line 189: query 'SET GLOBAL debug_dbug="+d,crash_commit_after"' failed: 2013: Lost connection to MySQL server during query

The result from queries just before the failure was:

< snip >

*** Test crashing slave at various points and check that it recovers crash-safe. ***

include/stop_slave.inc

SET GLOBAL debug_dbug="+d,inject_crash_before_write_rpl_slave_state";

START SLAVE;

connection server_1;

INSERT INTO t1 VALUES (4);

include/save_master_gtid.inc

connection server_2;

include/sync_with_master_gtid.inc

include/stop_slave.inc

START SLAVE;

SET GLOBAL debug_dbug="+d,crash_commit_before";

connection server_1;

INSERT INTO t1 VALUES (5);

include/save_master_gtid.inc

connection server_2;

include/sync_with_master_gtid.inc

include/stop_slave.inc

START SLAVE;

SET GLOBAL debug_dbug="+d,crash_commit_after";

More results from queries before failure can be found in /mnt/buildbot/build/mariadb-10.3.1/mysql-test/var/4/log/rpl_gtid_crash.log

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

Server log from this test:

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

2017-08-24 15:20:59 0 [Note] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld (mysqld 10.3.1-MariaDB-debug-log) starting as process 20334 ...

2017-08-24 15:20:59 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4162)

2017-08-24 15:20:59 0 [Note] Plugin 'partition' is disabled.

2017-08-24 15:20:59 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!

2017-08-24 15:20:59 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins

2017-08-24 15:20:59 0 [Note] InnoDB: Uses event mutexes

2017-08-24 15:20:59 0 [Note] InnoDB: Compressed tables use zlib 1.2.3.4

2017-08-24 15:20:59 0 [Note] InnoDB: Using Linux native AIO

2017-08-24 15:20:59 0 [Note] InnoDB: Number of pools: 1

2017-08-24 15:20:59 0 [Note] InnoDB: Using generic crc32 instructions

2017-08-24 15:20:59 0 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M

2017-08-24 15:20:59 0 [Note] InnoDB: Completed initialization of buffer pool

2017-08-24 15:20:59 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().

2017-08-24 15:20:59 0 [Note] InnoDB: 128 out of 128 rollback segments are active.

2017-08-24 15:20:59 0 [Note] InnoDB: Creating shared tablespace for temporary tables

2017-08-24 15:20:59 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...

2017-08-24 15:20:59 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.

2017-08-24 15:21:00 0 [Note] InnoDB: Waiting for purge to start

2017-08-24 15:21:00 0 [Note] InnoDB: 5.7.19 started; log sequence number 1632811

2017-08-24 15:21:00 0 [Note] InnoDB: Loading buffer pool(s) from /run/shm/var_auto_vtrH/4/mysqld.2/data/ib_buffer_pool

2017-08-24 15:21:00 0 [Note] InnoDB: Buffer pool(s) load completed at 170824 15:21:00

2017-08-24 15:21:00 0 [Note] Plugin 'SEQUENCE' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_CMP' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'FEEDBACK' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'user_variables' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.

2017-08-24 15:21:00 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.

2017-08-24 15:21:00 0 [Warning] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld: unknown option '--loose-pam-debug'

2017-08-24 15:21:00 0 [Note] Server socket created on IP: '127.0.0.1'.

2017-08-24 15:21:00 0 [Note] Reading of all Master_info entries succeded

2017-08-24 15:21:00 0 [Note] Added new Master_info '' to hash table

2017-08-24 15:21:00 0 [Note] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld: ready for connections.

Version: '10.3.1-MariaDB-debug-log'  socket: '/mnt/buildbot/build/mariadb-10.3.1/mysql-test/var/tmp/4/mysqld.2.sock'  port: 16001  Source distribution

2017-08-24 15:21:00 10 [Note] Deleted Master_info file '/mnt/buildbot/build/mariadb-10.3.1/mysql-test/var/4/mysqld.2/data/master.info'.

2017-08-24 15:21:00 10 [Note] Deleted Master_info file '/mnt/buildbot/build/mariadb-10.3.1/mysql-test/var/4/mysqld.2/data/relay-log.info'.

2017-08-24 15:21:00 10 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'

2017-08-24 15:21:00 10 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='', master_port='3306', master_log_file='', master_log_pos='4'. New state master_host='127.0.0.1', master_port='16000', master_log_file='master-bin.000001', master_log_pos='4'.

2017-08-24 15:21:00 12 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16000',replication started in log 'master-bin.000001' at position 4

2017-08-24 15:21:00 13 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 4, relay log './slave-relay-bin.000001' position: 4

2017-08-24 15:21:01 13 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000001' at position 1924

2017-08-24 15:21:01 12 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 1924

2017-08-24 15:21:01 10 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'

2017-08-24 15:21:01 10 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='16000', master_log_file='master-bin.000001', master_log_pos='1924'. New state master_host='127.0.0.1', master_port='16000', master_log_file='', master_log_pos='4'.

2017-08-24 15:21:01 10 [Note] Previous Using_Gtid=No. New Using_Gtid=Current_Pos

2017-08-24 15:21:01 14 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16000',replication starts at GTID position '0-1-7'

2017-08-24 15:21:01 15 [Note] Slave SQL thread initialized, starting replication in log 'FIRST' at position 4, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-7'

2017-08-24 15:21:02 14 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)

2017-08-24 15:21:02 14 [Note] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'master-bin.000001' at position 37150; GTID position '0-1-209'

2017-08-24 15:21:02 14 [ERROR] Slave I/O: error reconnecting to master 'root@127.0.0.1:16000' - retry-time: 1  maximum-retries: 100  message: Can't connect to MySQL server on '127.0.0.1' (111 "Connection refused"), Internal MariaDB error code: 2003

2017-08-24 15:21:06 14 [Note] Slave: connected to master 'root@127.0.0.1:16000',replication resumed in log 'master-bin.000001' at position 37150

2017-08-24 15:21:06 15 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 664; GTID position '0-1-211'

2017-08-24 15:21:06 14 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 664; GTID position 0-1-211

2017-08-24 15:21:07 16 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16000',replication starts at GTID position ''

2017-08-24 15:21:07 17 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 664, relay log './slave-relay-bin.000001' position: 4; GTID position ''

2017-08-24 15:21:07 16 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)

2017-08-24 15:21:07 16 [Note] Slave I/O thread: Failed reading log event, reconnecting to retry, log 'master-bin.000003' at position 375; GTID position '1-1-2,2-1-1,0-1-1'

2017-08-24 15:21:07 16 [ERROR] Slave I/O: error reconnecting to master 'root@127.0.0.1:16000' - retry-time: 1  maximum-retries: 100  message: Can't connect to MySQL server on '127.0.0.1' (111 "Connection refused"), Internal MariaDB error code: 2003

2017-08-24 15:21:10 16 [Note] Slave: connected to master 'root@127.0.0.1:16000',replication resumed in log 'master-bin.000003' at position 375

2017-08-24 15:21:10 17 [Note] Error reading relay log event: slave SQL thread was killed

2017-08-24 15:21:10 17 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000004' at position 375; GTID position '0-1-1,1-1-2,2-1-1'

2017-08-24 15:21:10 16 [Note] Slave I/O thread exiting, read up to log 'master-bin.000004', position 375; GTID position 1-1-2,2-1-1,0-1-1

2017-08-24 15:21:10 19 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000004' at position 375, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-1,1-1-2,2-1-1'

2017-08-24 15:21:10 18 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16000',replication starts at GTID position '1-1-2,0-1-1,2-1-1'

SIGKILL myself

2017-08-24 15:21:11 0 [Note] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld (mysqld 10.3.1-MariaDB-debug-log) starting as process 21000 ...

2017-08-24 15:21:11 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4162)

2017-08-24 15:21:11 0 [Note] Plugin 'partition' is disabled.

2017-08-24 15:21:11 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!

2017-08-24 15:21:11 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins

2017-08-24 15:21:11 0 [Note] InnoDB: Uses event mutexes

2017-08-24 15:21:11 0 [Note] InnoDB: Compressed tables use zlib 1.2.3.4

2017-08-24 15:21:11 0 [Note] InnoDB: Using Linux native AIO

2017-08-24 15:21:11 0 [Note] InnoDB: Number of pools: 1

2017-08-24 15:21:11 0 [Note] InnoDB: Using generic crc32 instructions

2017-08-24 15:21:11 0 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M

2017-08-24 15:21:11 0 [Note] InnoDB: Completed initialization of buffer pool

2017-08-24 15:21:11 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().

2017-08-24 15:21:11 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=1870767

2017-08-24 15:21:11 0 [Note] InnoDB: Last binlog file './slave-bin.000001', position 981

2017-08-24 15:21:11 0 [Note] InnoDB: 128 out of 128 rollback segments are active.

2017-08-24 15:21:11 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"

2017-08-24 15:21:11 0 [Note] InnoDB: Creating shared tablespace for temporary tables

2017-08-24 15:21:11 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...

2017-08-24 15:21:11 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.

2017-08-24 15:21:12 0 [Note] InnoDB: Waiting for purge to start

2017-08-24 15:21:12 0 [Note] InnoDB: 5.7.19 started; log sequence number 1870828

2017-08-24 15:21:12 0 [Note] InnoDB: Loading buffer pool(s) from /run/shm/var_auto_vtrH/4/mysqld.2/data/ib_buffer_pool

2017-08-24 15:21:12 0 [Note] InnoDB: Buffer pool(s) load completed at 170824 15:21:12

2017-08-24 15:21:12 0 [Note] Plugin 'SEQUENCE' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_CMP' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'FEEDBACK' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'user_variables' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.

2017-08-24 15:21:12 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.

2017-08-24 15:21:12 0 [Warning] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld: unknown option '--loose-pam-debug'

2017-08-24 15:21:12 0 [Note] Recovering after a crash using slave-bin

2017-08-24 15:21:12 0 [Note] Starting crash recovery...

2017-08-24 15:21:12 0 [Note] Crash recovery finished.

2017-08-24 15:21:12 0 [Note] Server socket created on IP: '127.0.0.1'.

2017-08-24 15:21:12 0 [Note] Reading of all Master_info entries succeded

2017-08-24 15:21:12 0 [Note] Added new Master_info '' to hash table

2017-08-24 15:21:12 10 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16000',replication starts at GTID position '1-1-2,0-1-1,2-1-1'

2017-08-24 15:21:12 0 [Note] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld: ready for connections.

Version: '10.3.1-MariaDB-debug-log'  socket: '/mnt/buildbot/build/mariadb-10.3.1/mysql-test/var/tmp/4/mysqld.2.sock'  port: 16001  Source distribution

2017-08-24 15:21:12 11 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000004' at position 4, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-1,1-1-2,2-1-1'

2017-08-24 15:21:12 11 [Note] Error reading relay log event: slave SQL thread was killed

2017-08-24 15:21:12 11 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000004' at position 540; GTID position '0-1-2,1-1-2,2-1-1'

2017-08-24 15:21:12 10 [Note] Slave I/O thread exiting, read up to log 'master-bin.000004', position 540; GTID position 1-1-2,0-1-2,2-1-1

2017-08-24 15:21:13 13 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16000',replication starts at GTID position '1-1-2,0-1-2,2-1-1'

2017-08-24 15:21:13 14 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000004' at position 540, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-2,1-1-2,2-1-1'

SIGKILL myself

2017-08-24 15:21:13 0 [Note] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld (mysqld 10.3.1-MariaDB-debug-log) starting as process 21089 ...

2017-08-24 15:21:13 0 [Warning] Could not increase number of max_open_files to more than 1024 (request: 4162)

2017-08-24 15:21:13 0 [Note] Plugin 'partition' is disabled.

2017-08-24 15:21:13 0 [Note] InnoDB: !!!!!!!! UNIV_DEBUG switched on !!!!!!!!!

2017-08-24 15:21:13 0 [Note] InnoDB: Mutexes and rw_locks use GCC atomic builtins

2017-08-24 15:21:13 0 [Note] InnoDB: Uses event mutexes

2017-08-24 15:21:13 0 [Note] InnoDB: Compressed tables use zlib 1.2.3.4

2017-08-24 15:21:13 0 [Note] InnoDB: Using Linux native AIO

2017-08-24 15:21:13 0 [Note] InnoDB: Number of pools: 1

2017-08-24 15:21:13 0 [Note] InnoDB: Using generic crc32 instructions

2017-08-24 15:21:13 0 [Note] InnoDB: Initializing buffer pool, total size = 8M, instances = 1, chunk size = 8M

2017-08-24 15:21:13 0 [Note] InnoDB: Completed initialization of buffer pool

2017-08-24 15:21:13 0 [Note] InnoDB: If the mysqld execution user is authorized, page cleaner thread priority can be changed. See the man page of setpriority().

2017-08-24 15:21:13 0 [Note] InnoDB: Starting crash recovery from checkpoint LSN=1870915

2017-08-24 15:21:14 0 [Note] InnoDB: Transaction 2050 was in the XA prepared state.

2017-08-24 15:21:14 0 [Note] InnoDB: 1 transaction(s) which must be rolled back or cleaned up in total 0 row operations to undo

2017-08-24 15:21:14 0 [Note] InnoDB: Trx id counter is 2560

2017-08-24 15:21:14 0 [Note] InnoDB: Starting final batch to recover 2 pages from redo log.

2017-08-24 15:21:14 0 [Note] InnoDB: Last binlog file './slave-bin.000001', position 981

2017-08-24 15:21:15 0 [Note] InnoDB: Starting in background the rollback of recovered transactions

2017-08-24 15:21:15 0 [Note] InnoDB: Rollback of non-prepared transactions completed

2017-08-24 15:21:15 0 [Note] InnoDB: 128 out of 128 rollback segments are active.

2017-08-24 15:21:15 0 [Note] InnoDB: Removed temporary tablespace data file: "ibtmp1"

2017-08-24 15:21:15 0 [Note] InnoDB: Creating shared tablespace for temporary tables

2017-08-24 15:21:15 0 [Note] InnoDB: Setting file './ibtmp1' size to 12 MB. Physically writing the file full; Please wait ...

2017-08-24 15:21:15 0 [Note] InnoDB: File './ibtmp1' size is now 12 MB.

2017-08-24 15:21:15 0 [Note] InnoDB: Waiting for purge to start

2017-08-24 15:21:15 0 [Note] InnoDB: 5.7.19 started; log sequence number 1871350

2017-08-24 15:21:15 0 [Note] InnoDB: Loading buffer pool(s) from /run/shm/var_auto_vtrH/4/mysqld.2/data/ib_buffer_pool

2017-08-24 15:21:15 0 [Note] InnoDB: Buffer pool(s) load completed at 170824 15:21:15

2017-08-24 15:21:15 0 [Note] Plugin 'SEQUENCE' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_SYS_DATAFILES' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_SYS_TABLESTATS' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_TABLESPACES_SCRUBBING' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_CMP' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_FT_DELETED' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_CMP_RESET' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_LOCK_WAITS' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_TABLESPACES_ENCRYPTION' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_CMPMEM_RESET' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'FEEDBACK' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_FT_INDEX_TABLE' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_CMP_PER_INDEX_RESET' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'user_variables' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_FT_INDEX_CACHE' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_FT_BEING_DELETED' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_FT_DEFAULT_STOPWORD' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_FT_CONFIG' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_SYS_TABLESPACES' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_MUTEXES' is disabled.

2017-08-24 15:21:15 0 [Note] Plugin 'INNODB_SYS_SEMAPHORE_WAITS' is disabled.

2017-08-24 15:21:15 0 [Warning] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld: unknown option '--loose-pam-debug'

2017-08-24 15:21:15 0 [Note] Recovering after a crash using slave-bin

2017-08-24 15:21:15 0 [Note] Starting crash recovery...

2017-08-24 15:21:15 0 [Note] InnoDB: Starting recovery for XA transactions...

2017-08-24 15:21:15 0 [Note] InnoDB: Transaction 2050 in prepared state after recovery

2017-08-24 15:21:15 0 [Note] InnoDB: Transaction contains changes to 2 rows

2017-08-24 15:21:15 0 [Note] InnoDB: 1 transactions in prepared state after recovery

2017-08-24 15:21:15 0 [Note] Found 1 prepared transaction(s) in InnoDB

2017-08-24 15:21:15 0 [Note] commit xid 'MySQLXid\2\0\0\0\4\0\0\0\0\0\0\0'

2017-08-24 15:21:15 0 [Note] Crash recovery finished.

2017-08-24 15:21:15 0 [Note] Server socket created on IP: '127.0.0.1'.

2017-08-24 15:21:15 0 [Note] Reading of all Master_info entries succeded

2017-08-24 15:21:15 0 [Note] Added new Master_info '' to hash table

2017-08-24 15:21:15 0 [Note] /mnt/buildbot/build/mariadb-10.3.1/sql/mysqld: ready for connections.

Version: '10.3.1-MariaDB-debug-log'  socket: '/mnt/buildbot/build/mariadb-10.3.1/mysql-test/var/tmp/4/mysqld.2.sock'  port: 16001  Source distribution

2017-08-24 15:21:15 11 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000004' at position 540, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-2,1-1-2,2-1-1'

2017-08-24 15:21:15 10 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16000',replication starts at GTID position '1-1-2,0-1-2,2-1-1'

2017-08-24 15:21:16 11 [Note] Error reading relay log event: slave SQL thread was killed

2017-08-24 15:21:16 11 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000004' at position 705; GTID position '0-1-3,1-1-2,2-1-1'

2017-08-24 15:21:16 10 [Note] Slave I/O thread exiting, read up to log 'master-bin.000004', position 705; GTID position 1-1-2,0-1-3,2-1-1

2017-08-24 15:21:16 14 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000004' at position 705, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-3,1-1-2,2-1-1'

2017-08-24 15:21:16 13 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16000',replication starts at GTID position '1-1-2,0-1-3,2-1-1'

SIGKILL myself

----------SERVER LOG END-------------