[MDEV-12730] Assertion `count > 0' failed in rpl_parallel_thread_pool::get_thread, rpl.rpl_parallel failed in buildbot Created: 2017-05-08  Updated: 2018-01-24  Resolved: 2018-01-24

Status: Closed
Project: MariaDB Server
Component/s: Replication, Tests
Affects Version/s: 10.2
Fix Version/s: 10.2.13

Type: Bug Priority: Major
Reporter: Elena Stepanova Assignee: Michael Widenius
Resolution: Fixed Votes: 0
Labels: None


 Description   

http://buildbot.askmonty.org/buildbot/builders/kvm-fulltest2/builds/7937/steps/test_3/logs/stdio
(with ps-protocol)

rpl.rpl_parallel 'innodb,mix'            w4 [ fail ]
 
        Test ended at 2017-05-02 03:59:03
 
 
 
CURRENT_TEST: rpl.rpl_parallel
 
mysqltest: In included file "./include/wait_for_slave_param.inc": 
included from ./include/wait_for_slave_sql_error.inc at line 41:
 
included from ./extra/rpl_tests/rpl_parallel.inc at line 1476:
 
included from /mnt/buildbot/build/mariadb-10.2.6/mysql-test/suite/rpl/t/rpl_parallel.test at line 2:
 
At line 119: query 'let $_show_slave_status_value= query_get_value("SHOW SLAVE STATUS", $slave_param, 1)' failed: 2013: Lost connection to MySQL server during query
 
 
 
The result from queries just before the failure was:
 
< snip >
 
INSERT INTO t2 VALUES (32);
 
FLUSH LOGS;
 
INSERT INTO t2 VALUES (33);
 
INSERT INTO t2 VALUES (34);
 
SELECT * FROM t2 WHERE a >= 30 ORDER BY a;
 
a
 
31
 
32
 
33
 
34
 
include/save_master_gtid.inc
 
connection server_2;
 
include/wait_for_slave_sql_error.inc [errno=1062]
 
connection server_2;
 
include/stop_slave_io.inc
 
SET GLOBAL slave_parallel_threads=10;
 
START SLAVE;
 
include/wait_for_slave_sql_error.inc [errno=1062]
 
START SLAVE SQL_THREAD;
 
include/wait_for_slave_sql_error.inc [errno=1062]
 
 
 
More results from queries before failure can be found in /mnt/buildbot/build/mariadb-10.2.6/mysql-test/var/4/log/rpl_parallel.log
 
 
 
 
 
Server [mysqld.2 - pid: 21076, winpid: 21076, exit: 256] failed during test run
 
Server log from this test:
 
----------SERVER LOG START-----------
 
2017-05-02  3:58:59 2897668928 [Note] Deleted Master_info file '/run/shm/var_auto_QdH7/4/mysqld.2/data/master.info'.
 
2017-05-02  3:58:59 2897668928 [Note] Deleted Master_info file '/run/shm/var_auto_QdH7/4/mysqld.2/data/relay-log.info'.
 
2017-05-02  3:58:59 2897668928 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'
 
2017-05-02  3:58:59 2897668928 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='16040', 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'.
 
2017-05-02  3:58:59 2766142272 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication started in log 'master-bin.000001' at position 4
 
2017-05-02  3:58:59 2822761280 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 4, relay log './slave-relay-bin.000001' position: 4
 
2017-05-02  3:58:59 2822761280 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:58:59 2822761280 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000001' at position 329
 
2017-05-02  3:58:59 2766142272 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 329
 
2017-05-02  3:58:59 2897668928 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'
 
2017-05-02  3:58:59 2897668928 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='16040', master_log_file='master-bin.000001', master_log_pos='329'. New state master_host='127.0.0.1', master_port='16040', master_log_file='master-bin.000001', master_log_pos='329'.
 
2017-05-02  3:58:59 2897668928 [Note] Previous Using_Gtid=No. New Using_Gtid=Slave_Pos
 
2017-05-02  3:58:59 2822761280 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position ''
 
2017-05-02  3:58:59 2766142272 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 329, relay log './slave-relay-bin.000001' position: 4; GTID position ''
 
2017-05-02  3:58:59 2766142272 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:58:59 2766142272 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000001' at position 329; GTID position ''
 
2017-05-02  3:58:59 2822761280 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 329; GTID position 
2017-05-02  3:58:59 2766142272 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position ''
 
2017-05-02  3:58:59 2770008896 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 329, relay log './slave-relay-bin.000001' position: 4; GTID position ''
 
2017-05-02  3:58:59 2770008896 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:58:59 2770008896 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000001' at position 2131; GTID position '0-1-9,1-1-1'
 
2017-05-02  3:58:59 2766142272 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 2131; GTID position 1-1-1,0-1-9
 
2017-05-02  3:58:59 2770008896 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-1,0-1-9'
 
2017-05-02  3:58:59 2822458176 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 2131, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-9,1-1-1'
 
2017-05-02  3:58:59 2822458176 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:58:59 2822458176 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000001' at position 2714; GTID position '0-1-9,1-1-2,2-1-1'
 
2017-05-02  3:58:59 2770008896 [Note] Slave I/O thread exiting, read up to log 'master-bin.000001', position 2714; GTID position 1-1-2,2-1-1,0-1-9
 
2017-05-02  3:58:59 2822458176 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-2,0-1-9,2-1-1'
 
2017-05-02  3:58:59 2770008896 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000001' at position 2714, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-9,1-1-2,2-1-1'
 
2017-05-02  3:58:59 2770008896 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:58:59 2770008896 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 1520; GTID position '0-1-14,1-1-2,2-1-1'
 
2017-05-02  3:58:59 2822458176 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 1520; GTID position 1-1-2,0-1-14,2-1-1
 
2017-05-02  3:58:59 2770008896 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-2,0-1-14,2-1-1'
 
2017-05-02  3:58:59 2843085632 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 1520, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-14,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2843085632 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:00 2843085632 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 1969; GTID position '0-1-15,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2770008896 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 2307; GTID position 1-1-2,0-1-17,2-1-1
 
2017-05-02  3:59:00 2843085632 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-2,0-1-15,2-1-1'
 
2017-05-02  3:59:00 2822458176 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 1969, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-15,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2822458176 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:00 2822458176 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 2307; GTID position '0-1-17,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2843085632 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 2307; GTID position 1-1-2,0-1-17,2-1-1
 
2017-05-02  3:59:00 2822155072 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-2,0-1-17,2-1-1'
 
2017-05-02  3:59:00 2822458176 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 2307, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-17,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2769705792 [ERROR] Slave SQL: Connection was killed, Gtid 0-1-19, Internal MariaDB error code: 1927
 
2017-05-02  3:59:00 2769705792 [Warning] Slave: Connection was killed Error_code: 1927
 
2017-05-02  3:59:00 2769705792 [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.000002' position 2307; GTID position '0-1-17,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2822458176 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:00 2765839168 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
 
2017-05-02  3:59:00 2765839168 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
 
2017-05-02  3:59:00 2765839168 [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.000002' position 2307; GTID position '0-1-17,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2822458176 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 2602; GTID position '0-1-18,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2822155072 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 3233; GTID position 1-1-2,0-1-20,2-1-1
 
2017-05-02  3:59:00 2822155072 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-2,0-1-18,2-1-1'
 
2017-05-02  3:59:00 2766142272 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 2602, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-18,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2766142272 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:00 2766142272 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 3401; GTID position '0-1-21,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2822155072 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 3401; GTID position 1-1-2,0-1-21,2-1-1
 
2017-05-02  3:59:00 2770008896 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-2,0-1-21,2-1-1'
 
2017-05-02  3:59:00 2766142272 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 3401, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-21,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2770312000 [ERROR] Slave SQL: Connection was killed, Gtid 0-1-23, Internal MariaDB error code: 1927
 
2017-05-02  3:59:00 2770312000 [Warning] Slave: Connection was killed Error_code: 1927
 
2017-05-02  3:59:00 2770312000 [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.000002' position 3401; GTID position '0-1-21,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2766142272 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:00 2765536064 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
 
2017-05-02  3:59:00 2765536064 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
 
2017-05-02  3:59:00 2765536064 [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.000002' position 3401; GTID position '0-1-21,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2766142272 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 3696; GTID position '0-1-22,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2766142272 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 3696, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-22,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2766142272 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:00 2766142272 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 4495; GTID position '0-1-25,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2770008896 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 4495; GTID position 1-1-2,0-1-25,2-1-1
 
2017-05-02  3:59:00 2766142272 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-2,0-1-25,2-1-1'
 
2017-05-02  3:59:00 2822458176 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 4495, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-25,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2822458176 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:00 2822458176 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 4495; GTID position '0-1-25,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2766142272 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 4495; GTID position 1-1-2,0-1-25,2-1-1
 
2017-05-02  3:59:00 2897668928 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'
 
2017-05-02  3:59:00 2897668928 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='16040', master_log_file='master-bin.000002', master_log_pos='4495'. New state master_host='127.0.0.1', master_port='16040', master_log_file='master-bin.000002', master_log_pos='4495'.
 
2017-05-02  3:59:00 2897668928 [Note] Previous Using_Gtid=Slave_Pos. New Using_Gtid=No
 
2017-05-02  3:59:00 2822458176 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication started in log 'master-bin.000002' at position 4495
 
2017-05-02  3:59:00 2765536064 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 4495, relay log './slave-relay-bin.000001' position: 4
 
2017-05-02  3:59:00 2764045120 [ERROR] Slave SQL: Connection was killed, Gtid 0-1-27, Internal MariaDB error code: 1927
 
2017-05-02  3:59:00 2764045120 [Warning] Slave: Connection was killed Error_code: 1927
 
2017-05-02  3:59:00 2764045120 [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.000002' position 4495
 
2017-05-02  3:59:00 2765536064 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:00 2822761280 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
 
2017-05-02  3:59:00 2822761280 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
 
2017-05-02  3:59:00 2822761280 [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.000002' position 4495
 
2017-05-02  3:59:00 2765536064 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 4790
 
2017-05-02  3:59:00 2765536064 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 4790, relay log './slave-relay-bin.000002' position: 851
 
2017-05-02  3:59:00 2765536064 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:00 2765536064 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 5589
 
2017-05-02  3:59:00 2822458176 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 5589
 
2017-05-02  3:59:00 2897668928 [Note] Master connection name: ''  Master_info_file: 'master.info'  Relay_info_file: 'relay-log.info'
 
2017-05-02  3:59:00 2897668928 [Note] 'CHANGE MASTER TO executed'. Previous state master_host='127.0.0.1', master_port='16040', master_log_file='master-bin.000002', master_log_pos='5589'. New state master_host='127.0.0.1', master_port='16040', master_log_file='master-bin.000002', master_log_pos='5589'.
 
2017-05-02  3:59:00 2897668928 [Note] Previous Using_Gtid=No. New Using_Gtid=Slave_Pos
 
2017-05-02  3:59:00 2765839168 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-2,0-1-29,2-1-1'
 
2017-05-02  3:59:00 2765536064 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 5589, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-29,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2765536064 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:00 2765536064 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 5589; GTID position '0-1-29,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2765839168 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 5589; GTID position 1-1-2,0-1-29,2-1-1
 
2017-05-02  3:59:00 2770008896 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-2,0-1-29,2-1-1'
 
2017-05-02  3:59:00 2822155072 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 5589, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-29,1-1-2,2-1-1'
 
2017-05-02  3:59:00 2822761280 [ERROR] Slave SQL: Connection was killed, Gtid 0-1-33, Internal MariaDB error code: 1927
 
2017-05-02  3:59:00 2822761280 [Warning] Slave: Connection was killed Error_code: 1927
 
2017-05-02  3:59:00 2822761280 [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.000002' position 7301; GTID position '0-1-30,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:00 2822155072 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:00 2822155072 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 7556; GTID position '0-1-31,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:00 2770008896 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 8111; GTID position 1-1-3,0-1-34,3-1-1,2-1-2
 
2017-05-02  3:59:00 2770008896 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-3,0-1-31,3-1-1,2-1-2'
 
2017-05-02  3:59:00 2822155072 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 7556, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-31,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2822155072 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:01 2822155072 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 8281; GTID position '0-1-35,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2770008896 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 8281; GTID position 1-1-3,0-1-35,3-1-1,2-1-2
 
2017-05-02  3:59:01 2822155072 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-3,0-1-35,3-1-1,2-1-2'
 
2017-05-02  3:59:01 2822458176 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 8281, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-35,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2822458176 [ERROR] Slave SQL: Connection was killed, Internal MariaDB error code: 1927
 
2017-05-02  3:59:01 2822458176 [Warning] Slave: Connection was killed Error_code: 1927
 
2017-05-02  3:59:01 2822458176 [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.000002' position 8281; GTID position '0-1-35,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2822458176 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 8520; GTID position '0-1-36,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2822155072 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 18698; GTID position 1-1-3,0-1-37,3-1-1,2-1-2
 
2017-05-02  3:59:01 2822155072 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-3,0-1-36,3-1-1,2-1-2'
 
2017-05-02  3:59:01 2822458176 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 8520, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-36,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2822458176 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:01 2822458176 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 18866; GTID position '0-1-38,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2822155072 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 18866; GTID position 1-1-3,0-1-38,3-1-1,2-1-2
 
2017-05-02  3:59:01 2822458176 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-3,0-1-38,3-1-1,2-1-2'
 
2017-05-02  3:59:01 2822155072 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 18866, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-38,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2822155072 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:01 2822155072 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 18866; GTID position '0-1-38,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2822458176 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 18866; GTID position 1-1-3,0-1-38,3-1-1,2-1-2
 
2017-05-02  3:59:01 2822155072 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-3,0-1-38,3-1-1,2-1-2'
 
2017-05-02  3:59:01 2843085632 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 18866, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-38,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2843085632 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:01 2843085632 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 20150; GTID position '0-1-44,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2822155072 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 20150; GTID position 1-1-3,0-1-44,3-1-1,2-1-2
 
2017-05-02  3:59:01 2843085632 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-3,0-1-44,3-1-1,2-1-2'
 
2017-05-02  3:59:01 2822155072 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 20150, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-44,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2822155072 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:01 2822155072 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 20578; GTID position '0-1-46,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2843085632 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 20578; GTID position 1-1-3,0-1-46,3-1-1,2-1-2
 
2017-05-02  3:59:01 2764045120 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-3,0-1-46,3-1-1,2-1-2'
 
2017-05-02  3:59:01 2822155072 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 20578, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-46,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2769705792 [ERROR] Slave SQL: Error 'Duplicate entry '111' for key 'PRIMARY'' on query. Default database: 'test'. Query: 'INSERT INTO t3 VALUES (111, 2)', Gtid 0-1-48, Internal MariaDB error code: 1062
 
2017-05-02  3:59:01 2769705792 [Warning] Slave: Duplicate entry '111' for key 'PRIMARY' Error_code: 1062
 
2017-05-02  3:59:01 2769705792 [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.000002' position 20748; GTID position '0-1-47,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2822155072 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:01 2765536064 [ERROR] Slave (additional info): Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
 
2017-05-02  3:59:01 2765536064 [Warning] Slave: Commit failed due to failure of an earlier commit on which this one depends Error_code: 1964
 
2017-05-02  3:59:01 2765536064 [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.000002' position 20748; GTID position '0-1-47,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2822155072 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 20748; GTID position '0-1-47,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2765839168 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 20748, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-47,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2765839168 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:01 2765839168 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 21092; GTID position '0-1-49,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2764045120 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 21092; GTID position 1-1-3,0-1-49,3-1-1,2-1-2
 
2017-05-02  3:59:01 2770008896 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-3,0-1-49,3-1-1,2-1-2'
 
2017-05-02  3:59:01 2765839168 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 21092, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-49,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2765839168 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:01 2765839168 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 21825; GTID position '0-1-53,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2770008896 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 21825; GTID position 1-1-3,0-1-53,3-1-1,2-1-2
 
2017-05-02  3:59:01 2822155072 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-3,0-1-53,3-1-1,2-1-2'
 
2017-05-02  3:59:01 2765839168 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 21825, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-53,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2765839168 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:01 2765839168 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 22534; GTID position '0-1-57,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:01 2822155072 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 22534; GTID position 1-1-3,0-1-57,3-1-1,2-1-2
 
2017-05-02  3:59:01 2822155072 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-3,0-1-57,3-1-1,2-1-2'
 
2017-05-02  3:59:01 2765839168 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 22534, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-57,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:02 2765839168 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:02 2765839168 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000002' at position 23284; GTID position '0-1-61,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:02 2822155072 [Note] Slave I/O thread exiting, read up to log 'master-bin.000002', position 23284; GTID position 1-1-3,0-1-61,3-1-1,2-1-2
 
2017-05-02  3:59:02 2843388736 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000002' at position 23284, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-61,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:02 2765839168 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-3,0-1-61,3-1-1,2-1-2'
 
2017-05-02  3:59:02 2822458176 [ERROR] Slave SQL: Query partially completed on the master (error on master: 1317) and was aborted. There is a chance that your master is inconsistent at this point. If you are sure that your master is ok, run this query manually on the slave and then restart the slave with SET GLOBAL SQL_SLAVE_SKIP_COUNTER=1; START SLAVE; . Query: 'INSERT INTO t6 VALUES (1), (2), (3)', Gtid 0-1-68, Internal MariaDB error code: 1317
 
2017-05-02  3:59:02 2822458176 [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.000003' position 797; GTID position '0-1-67,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:02 2843388736 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:02 2843388736 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000003' at position 797; GTID position '0-1-67,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:02 2765839168 [Note] Slave I/O thread exiting, read up to log 'master-bin.000003', position 1014; GTID position 1-1-3,0-1-68,3-1-1,2-1-2
 
2017-05-02  3:59:02 2765839168 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-3,0-1-68,3-1-1,2-1-2'
 
2017-05-02  3:59:02 2822458176 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000003' at position 797, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-68,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:02 2822458176 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:02 2822458176 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000003' at position 1387; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:02 2765839168 [Note] Slave I/O thread exiting, read up to log 'master-bin.000003', position 1387; GTID position 1-1-3,0-1-70,3-1-1,2-1-2
 
2017-05-02  3:59:02 2822458176 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-3,0-1-70,3-1-1,2-1-2'
 
2017-05-02  3:59:02 2765839168 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000003' at position 1387, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:02 2765839168 [ERROR] Slave SQL: Error 'Duplicate entry '32' for key 'PRIMARY'' on query. Default database: 'test'. Query: 'INSERT INTO t2 VALUES (32)', Gtid 0-1-71, Internal MariaDB error code: 1062
 
2017-05-02  3:59:02 2765839168 [Warning] Slave: Duplicate entry '32' for key 'PRIMARY' Error_code: 1062
 
2017-05-02  3:59:02 2765839168 [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.000003' position 1387; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:02 2765839168 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000003' at position 1387; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:02 2822458176 [ERROR] Error reading packet from server: Lost connection to MySQL server during query (server_errno=2013)
 
2017-05-02  3:59:02 2822458176 [Note] Slave I/O thread exiting, read up to log 'master-bin.000004', position 767; GTID position 1-1-3,0-1-73,3-1-1,2-1-2
 
2017-05-02  3:59:02 2822458176 [Note] Slave I/O thread: connected to master 'root@127.0.0.1:16040',replication starts at GTID position '1-1-3,0-1-70,3-1-1,2-1-2'
 
2017-05-02  3:59:02 2765839168 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000003' at position 1387, relay log './slave-relay-bin.000001' position: 4; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:02 2769705792 [ERROR] Slave SQL: Error 'Duplicate entry '32' for key 'PRIMARY'' on query. Default database: 'test'. Query: 'INSERT INTO t2 VALUES (32)', Gtid 0-1-71, Internal MariaDB error code: 1062
 
2017-05-02  3:59:02 2769705792 [Warning] Slave: Duplicate entry '32' for key 'PRIMARY' Error_code: 1062
 
2017-05-02  3:59:02 2769705792 [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.000003' position 1387; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:02 2765839168 [Note] Error reading relay log event: slave SQL thread was killed
 
2017-05-02  3:59:02 2765839168 [Note] Slave SQL thread exiting, replication stopped in log 'master-bin.000003' at position 1387; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
 
2017-05-02  3:59:02 2843085632 [Note] Slave SQL thread initialized, starting replication in log 'master-bin.000003' at position 1387, relay log './slave-relay-bin.000002' position: 4; GTID position '0-1-70,1-1-3,2-1-2,3-1-1'
 
mysqld: /home/buildbot/buildbot/build/mariadb-10.2.6/sql/rpl_parallel.cc:1940: rpl_parallel_thread* rpl_parallel_thread_pool::get_thread(rpl_parallel_thread**, rpl_parallel_entry*): Assertion `count > 0' failed.
 
170502  3:59:02 [ERROR] mysqld got signal 6 ;
 
This could be because you hit a bug. It is also possible that this binary
 
or one of the libraries it was linked against is corrupt, improperly built,
 
or misconfigured. This error can also be caused by malfunctioning hardware.
 
 
 
To report this bug, see https://mariadb.com/kb/en/reporting-bugs
 
 
 
We will try our best to scrape up some info that will hopefully help
 
diagnose the problem, but since we have already crashed, 
something is definitely wrong and this may fail.
 
 
 
Server version: 10.2.6-MariaDB-debug-log
 
key_buffer_size=1048576
 
read_buffer_size=131072
 
max_used_connections=7
 
max_threads=153
 
thread_count=16
 
It is possible that mysqld could use up to 
key_buffer_size + (read_buffer_size + sort_buffer_size)*max_threads = 61863 K  bytes of memory
 
Hope that's ok; if not, decrease some variables in the equation.
 
 
 
Thread pointer: 0xa502e6a8
 
Attempting backtrace. You can use the following information to find out
 
where mysqld died. If you see no messages after this, something went
 
terribly wrong...
 
stack_bottom = 0xa975fa94 thread_stack 0x49000
 
/mnt/buildbot/build/mariadb-10.2.6/sql/mysqld(my_print_stacktrace+0x32)[0x8ce9b6a]
 
/mnt/buildbot/build/mariadb-10.2.6/sql/mysqld(handle_fatal_signal+0x3c1)[0x859b719]
 
[0xb7789400]
 
[0xb7789424]
 
/lib/i386-linux-gnu/libc.so.6(gsignal+0x4f)[0xb72651ef]
 
/lib/i386-linux-gnu/libc.so.6(abort+0x175)[0xb7268835]
 
/lib/i386-linux-gnu/libc.so.6(+0x27095)[0xb725e095]
 
/lib/i386-linux-gnu/libc.so.6(+0x27147)[0xb725e147]
 
/mnt/buildbot/build/mariadb-10.2.6/sql/mysqld(_ZN24rpl_parallel_thread_pool10get_threadEPP19rpl_parallel_threadP18rpl_parallel_entry+0x49)[0x84e9343]
 
/mnt/buildbot/build/mariadb-10.2.6/sql/mysqld(_ZN18rpl_parallel_entry13choose_threadEP14rpl_group_infoPbP17PSI_stage_info_v1b+0x322)[0x84e9864]
 
/mnt/buildbot/build/mariadb-10.2.6/sql/mysqld(_ZN12rpl_parallel8do_eventEP14rpl_group_infoP9Log_eventy+0x62e)[0x84eaada]
 
/mnt/buildbot/build/mariadb-10.2.6/sql/mysqld[0x829313a]
 
/mnt/buildbot/build/mariadb-10.2.6/sql/mysqld(handle_slave_sql+0xf86)[0x8296d76]
 
/mnt/buildbot/build/mariadb-10.2.6/sql/mysqld[0x87aa2a8]
 
/lib/i386-linux-gnu/libpthread.so.0(+0x6d4c)[0xb7511d4c]
 
/lib/i386-linux-gnu/libc.so.6(clone+0x5e)[0xb7321ace]
 
 
 
Trying to get some variables.
 
Some pointers may be invalid and cause the dump to abort.
 
Query (0x0): 
Connection ID (thread ID): 828
 
Status: NOT_KILLED
 
 
 
Optimizer switch: index_merge=on,index_merge_union=on,index_merge_sort_union=on,index_merge_intersection=on,index_merge_sort_intersection=off,engine_condition_pushdown=off,index_condition_pushdown=on,derived_merge=on,derived_with_keys=on,firstmatch=on,loosescan=on,materialization=on,in_to_exists=on,semijoin=on,partial_match_rowid_merge=on,partial_match_table_scan=on,subquery_cache=on,mrr=off,mrr_cost_based=off,mrr_sort_keys=off,outer_join_with_cache=on,semijoin_with_cache=on,join_cache_incremental=on,join_cache_hashed=on,join_cache_bka=on,optimize_join_buffer_size=off,table_elimination=on,extended_keys=on,exists_to_in=on,orderby_uses_equalities=on,condition_pushdown_for_derived=on
 
 
 
The manual page at http://dev.mysql.com/doc/mysql/en/crashing.html contains
 
information that should help you find out what is causing the crash.
 
Writing a core file
 
----------SERVER LOG END-------------



 Comments   
Comment by Michael Widenius [ 2018-01-24 ]

The reason for this is that one thread can call rpl_parallel_resize_pool_if_no_slaves() while
another thread calls at the same time rpl_parallel_activate_pool(). If rpl_parallel_active_pool() is
called before rpl_parallel_resize_pool_if_no_slaves() has finished, pool->count will be set to 0
even if there exists active slave threads.

Added a mutex lock in rpl_parallel_activate_pool() to protect against this scenario, which seams to fix this issue.

Comment by Michael Widenius [ 2018-01-24 ]

Pushed

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